kinetic-c  v0.12.0
Seagate Kinetic Protocol Client Library for C
kinetic_logger.c
Go to the documentation of this file.
1 /*
2 * kinetic-c
3 * Copyright (C) 2015 Seagate Technology.
4 *
5 * This program is free software; you can redistribute it and/or
6 * modify it under the terms of the GNU General Public License
7 * as published by the Free Software Foundation; either version 2
8 * of the License, or (at your option) any later version.
9 *
10 * This program is distributed in the hope that it will be useful,
11 * but WITHOUT ANY WARRANTY; without even the implied warranty of
12 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
13 * GNU General Public License for more details.
14 *
15 * You should have received a copy of the GNU General Public License
16 * along with this program; if not, write to the Free Software
17 * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
18 *
19 */
20 
21 #include "kinetic_logger.h"
22 #include "kinetic_version_info.h"
23 #include <stdarg.h>
24 #include <stdio.h>
25 #include <string.h>
26 #include <stdlib.h>
27 #include <sys/time.h>
28 #include <stdlib.h>
29 #include <errno.h>
30 #include <pthread.h>
31 #include <time.h>
32 
33 #define BUFFER_SIZE 1024
34 #define BUFFER_MAX_STRLEN (BUFFER_SIZE-2)
35 
37 static FILE* KineticLoggerHandle = NULL;
38 static pthread_mutex_t BufferMutex = PTHREAD_MUTEX_INITIALIZER;
39 static char Buffer[BUFFER_SIZE];
40 
41 //------------------------------------------------------------------------------
42 // Private Method Declarations
43 
44 static inline bool is_level_enabled(int log_level);
45 static inline void lock_buffer(void);
46 static inline void unlock_buffer(void);
47 static void flush_buffer(void);
48 static inline char* get_buffer(void);
49 static inline void finish_buffer(void);
50 static void log_protobuf_message(int log_level, const ProtobufCMessage *msg, char* indent);
51 static void log_version_info(void);
52 
53 //------------------------------------------------------------------------------
54 // Public Method Definitions
55 
56 void KineticLogger_Init(const char* log_file, int log_level)
57 {
58  KineticLogLevel = -1;
59  pthread_mutex_init(&BufferMutex, NULL);
60 
61  KineticLoggerHandle = NULL;
62  if (log_file == NULL) {
63  printf("\nLogging kinetic-c output is disabled!\n");
64  return;
65  }
66  else {
67  KineticLogLevel = log_level;
68 
69  if (strncmp(log_file, "stdout", 4) == 0 || strncmp(log_file, "STDOUT", 4) == 0) {
70  if (log_level > 0) {
71  printf("Logging kinetic-c output to console (stdout) w/ log_level=%d\n", KineticLogLevel);
72  }
73  KineticLoggerHandle = stdout;
74  }
75  else {
76  if (log_level > 0) {
77  printf("Logging kinetic-c output to %s w/ log_level=%d\n", log_file, KineticLogLevel);
78  }
79  KineticLoggerHandle = fopen(log_file, "a+");
81  }
83  }
84 }
85 
87 {
88  if (KineticLogLevel >= 0 && KineticLoggerHandle != NULL) {
89  if (KineticLoggerHandle != stdout) {
90  fclose(KineticLoggerHandle);
91  }
92  KineticLoggerHandle = NULL;
93  }
94 }
95 
96 void KineticLogger_Log(int log_level, const char* message)
97 {
98  KineticLogger_LogPrintf(log_level, "%s", message);
99 }
100 
101 void KineticLogger_LogPrintf(int log_level, const char* format, ...)
102 {
103  if (KineticLoggerHandle == NULL) {
104  return;
105  }
106  if (format == NULL || !is_level_enabled(log_level)) {
107  return;
108  }
109 
110  char* buffer = NULL;
111  buffer = get_buffer();
112 
113  /* Add timestamp prefix */
114  struct timeval tv;
115  if (0 == gettimeofday(&tv, NULL)) {
116  fprintf(KineticLoggerHandle, "%08lld.%06lld ",
117  (long long)tv.tv_sec, (long long)tv.tv_usec);
118  }
119 
120  va_list arg_ptr;
121  va_start(arg_ptr, format);
122  int len = vsnprintf(buffer, BUFFER_MAX_STRLEN, format, arg_ptr);
123  va_end(arg_ptr);
124 
125  if (len > BUFFER_MAX_STRLEN) {
126  Buffer[BUFFER_MAX_STRLEN] = '\0';
127  }
128  strcat(Buffer, "\n");
129 
130  finish_buffer();
131 }
132 
133 static void log_version_info(void)
134 {
135  KineticLogger_LogPrintf(1, "kinetic-c version: v%s (protocol: v%s, commit: %s)",
137 }
138 
139 void KineticLogger_LogLocation(const char* filename, int line, const char* message)
140 {
141  if (filename == NULL || message == NULL) {
142  return;
143  }
144 
145  if (KineticLogLevel >= 0) {
146  KineticLogger_LogPrintf(1, "[@%s:%d] %s", filename, line, message);
147  }
148  else {
149  printf("\n[@%s:%d] %s\n", filename, line, message);
150  fflush(stdout);
151  }
152 }
153 
154 void KineticLogger_LogHeader(int log_level, const KineticPDUHeader* header)
155 {
156  if (header == NULL || !is_level_enabled(log_level)) {
157  return;
158  }
159 
160  KineticLogger_Log(log_level, "PDU Header:");
161  KineticLogger_LogPrintf(log_level, " versionPrefix: %c", header->versionPrefix);
162  KineticLogger_LogPrintf(log_level, " protobufLength: %d", header->protobufLength);
163  KineticLogger_LogPrintf(log_level, " valueLength: %d", header->valueLength);
164 }
165 
166 
167 // Helper macros and stuff for logging protobufs
168 #define LOG_INDENT " "
169 static char indent[64] = LOG_INDENT;
170 static const size_t max_indent = sizeof(indent)-3;
171 static int indent_overflow = 0;
172 
173 
174 static void log_proto_level_start(const char* name)
175 {
176  KineticLogger_LogPrintf(0, "%s%s {", indent, name); \
177  if (strlen(indent) < max_indent) {
178  strcat(indent, LOG_INDENT);
179  }
180  else {
181  indent_overflow++;
182  }
183 }
184 
185 static void log_proto_level_end(void)
186 {
187  if (indent_overflow == 0) {
188  indent[strlen(indent) - 2] = '\0';
189  }
190  else {
191  indent_overflow--;
192  }
193  KineticLogger_LogPrintf(0, "%s}", indent);
194 }
195 
196 static void log_proto_level_start_array(const char* name, unsigned quantity)
197 {
198  KineticLogger_LogPrintf(0, "%s%s: (%u elements)", indent, name, quantity);
199  KineticLogger_LogPrintf(0, "%s[", (indent));
200  if (strlen(indent) < max_indent) {
201  strcat(indent, LOG_INDENT);
202  }
203  else {
204  indent_overflow++;
205  }
206 }
207 
208 static void log_proto_level_end_array(void)
209 {
210  if (indent_overflow == 0) {
211  indent[strlen(indent) - 2] = '\0';
212  }
213  else {
214  indent_overflow--;
215  }
216  KineticLogger_LogPrintf(0, "%s]", indent);
217 }
218 
219 static int bytetoa(char* p_buf, uint8_t val)
220 {
221  // KineticLogger_LogPrintf(log_level, "Converting byte=%02u", val);
222  const uint8_t base = 16;
223  const int width = 2;
224  int i = width;
225  char c = 0;
226 
227  p_buf += width - 1;
228  do {
229  c = val % base;
230  val /= base;
231  if (c >= 10) c += 'A' - '0' - 10;
232  c += '0';
233  *p_buf-- = c;
234  }
235  while (--i);
236  return width;
237 }
238 
240  const ByteArray bytes, const int start, const int count)
241 {
242  int len = 0;
243  for (int i = 0; i < count; i++) {
244  p_buf[len++] = '\\';
245  len += bytetoa(&p_buf[len], bytes.data[start + i]);
246  }
247  p_buf[len] = '\0';
248  return len;
249 }
250 
251 #define BOOL_TO_STRING(_bool) (_bool) ? "true" : "false"
252 
253 static void LogUnboxed(int log_level,
254  void const * const fieldData,
255  ProtobufCFieldDescriptor const * const fieldDesc,
256  size_t const i,
257  char* log_indent)
258 {
259  switch (fieldDesc->type) {
260  case PROTOBUF_C_TYPE_INT32:
261  case PROTOBUF_C_TYPE_SINT32:
262  case PROTOBUF_C_TYPE_SFIXED32:
263  {
264  int32_t const * value = (int32_t const *)fieldData;
265  KineticLogger_LogPrintf(log_level, "%s%s: %ld", log_indent, fieldDesc->name, value[i]);
266  }
267  break;
268 
269  case PROTOBUF_C_TYPE_INT64:
270  case PROTOBUF_C_TYPE_SINT64:
271  case PROTOBUF_C_TYPE_SFIXED64:
272  {
273  int64_t* value = (int64_t*)fieldData;
274  KineticLogger_LogPrintf(log_level, "%s%s: %lld", log_indent, fieldDesc->name, value[i]);
275  }
276  break;
277 
278  case PROTOBUF_C_TYPE_UINT32:
279  case PROTOBUF_C_TYPE_FIXED32:
280  {
281  uint32_t* value = (uint32_t*)fieldData;
282  KineticLogger_LogPrintf(log_level, "%s%s: %lu", log_indent, fieldDesc->name, value[i]);
283  }
284  break;
285 
286  case PROTOBUF_C_TYPE_UINT64:
287  case PROTOBUF_C_TYPE_FIXED64:
288  {
289  uint64_t* value = (uint64_t*)fieldData;
290  KineticLogger_LogPrintf(log_level, "%s%s: %llu", log_indent, fieldDesc->name, value[i]);
291  }
292  break;
293 
294  case PROTOBUF_C_TYPE_FLOAT:
295  {
296  float* value = (float*)fieldData;
297  KineticLogger_LogPrintf(log_level, "%s%s: %f", log_indent, fieldDesc->name, value[i]);
298  }
299  break;
300 
301  case PROTOBUF_C_TYPE_DOUBLE:
302  {
303  double* value = (double*)fieldData;
304  KineticLogger_LogPrintf(log_level, "%s%s: %f", log_indent, fieldDesc->name, value[i]);
305  }
306  break;
307 
308  case PROTOBUF_C_TYPE_BOOL:
309  {
310  protobuf_c_boolean* value = (protobuf_c_boolean*)fieldData;
311  KineticLogger_LogPrintf(log_level, "%s%s: %s", log_indent, fieldDesc->name, BOOL_TO_STRING(value[i]));
312  }
313  break;
314 
315  case PROTOBUF_C_TYPE_STRING:
316  {
317  char** strings = (char**)fieldData;
318  KineticLogger_LogPrintf(log_level, "%s%s: %s", log_indent, fieldDesc->name, strings[i]);
319  }
320  break;
321 
322  case PROTOBUF_C_TYPE_BYTES:
323  {
324  ProtobufCBinaryData* value = (ProtobufCBinaryData*)fieldData;
325  log_proto_level_start(fieldDesc->name);
326  KineticLogger_LogByteArray(log_level, log_indent,
327  (ByteArray){.data = value[i].data,
328  .len = value[i].len});
330  }
331  break;
332 
333  case PROTOBUF_C_TYPE_ENUM:
334  {
335  int * value = (int*)fieldData;
336  ProtobufCEnumDescriptor const * enumDesc = fieldDesc->descriptor;
337  ProtobufCEnumValue const * enumVal = protobuf_c_enum_descriptor_get_value(enumDesc, value[i]);
338  KineticLogger_LogPrintf(log_level, "%s%s: %s", log_indent, fieldDesc->name, enumVal->name);
339  }
340  break;
341 
342  case PROTOBUF_C_TYPE_MESSAGE: // nested message
343  {
344  ProtobufCMessage** msg = (ProtobufCMessage**)fieldData;
345  if (msg[i] != NULL)
346  {
347  log_proto_level_start(fieldDesc->name);
348  log_protobuf_message(log_level, msg[i], log_indent);
350  }
351  } break;
352 
353  default:
354  KineticLogger_LogPrintf(log_level, "Invalid message field type!: %d", fieldDesc->type);
355  KINETIC_ASSERT(false); // should never get here!
356  break;
357  };
358 }
359 
360 static void log_protobuf_message(int log_level, ProtobufCMessage const * msg, char* log_indent)
361 {
362  if (msg == NULL || msg->descriptor == NULL || !is_level_enabled(log_level)) {
363  return;
364  }
365 
366  ProtobufCMessageDescriptor const * desc = msg->descriptor;
367  uint8_t const * pMsg = (uint8_t const *)msg;
368 
369  for (unsigned int i = 0; i < desc->n_fields; i++) {
370  ProtobufCFieldDescriptor const * fieldDesc = &desc->fields[i];
371 
372  if (fieldDesc == NULL) {
373  continue;
374  }
375 
376  switch(fieldDesc->label)
377  {
378  case PROTOBUF_C_LABEL_REQUIRED:
379  {
380  LogUnboxed(log_level, &pMsg[fieldDesc->offset], fieldDesc, 0, log_indent);
381  } break;
382  case PROTOBUF_C_LABEL_OPTIONAL:
383  {
384  protobuf_c_boolean const * quantifier = (protobuf_c_boolean const *)(void*)&pMsg[fieldDesc->quantifier_offset];
385  if ((*quantifier) && // only print out if it's there
386  // and a special case: if this is a message, don't show it if the message is NULL
387  (PROTOBUF_C_TYPE_MESSAGE != fieldDesc->type || ((ProtobufCMessage**)(void*)&pMsg[fieldDesc->offset])[0] != NULL))
388  {
389  // special case for nested command packed into commandBytes field
390  if ((protobuf_c_message_descriptor_get_field_by_name(desc, "commandBytes") == fieldDesc ) &&
391  (PROTOBUF_C_TYPE_BYTES == fieldDesc->type))
392  {
393  ProtobufCBinaryData* value = (ProtobufCBinaryData*)(void*)&pMsg[fieldDesc->offset];
394  if ((value->data != NULL) && (value->len > 0)) {
395  log_proto_level_start(fieldDesc->name);
396  Com__Seagate__Kinetic__Proto__Command * cmd = com__seagate__kinetic__proto__command__unpack(NULL, value->len, value->data);
397  log_protobuf_message(log_level, &cmd->base, log_indent);
400  }
401  }
402  else {
403  LogUnboxed(log_level, &pMsg[fieldDesc->offset], fieldDesc, 0, log_indent);
404  }
405  }
406  } break;
407  case PROTOBUF_C_LABEL_REPEATED:
408  {
409  unsigned const * quantifier = (unsigned const *)(void*)&pMsg[fieldDesc->quantifier_offset];
410  if (*quantifier > 0) {
411  log_proto_level_start_array(fieldDesc->name, *quantifier);
412  for (uint32_t j = 0; j < *quantifier; j++) {
413  void const ** box = (void const **)(void*)&pMsg[fieldDesc->offset];
414  LogUnboxed(log_level, *box, fieldDesc, j, log_indent);
415  }
417  }
418  } break;
419  }
420  }
421 }
422 
423 void KineticLogger_LogProtobuf(int log_level, const Com__Seagate__Kinetic__Proto__Message* msg)
424 {
425  if (msg == NULL || !is_level_enabled(log_level)) {
426  return;
427  }
428  indent_overflow = 0;
429 
430  KineticLogger_Log(log_level, "Kinetic Protobuf:");
431 
432  log_protobuf_message(log_level, &msg->base, indent);
433 }
434 
435 void KineticLogger_LogStatus(int log_level, Com__Seagate__Kinetic__Proto__Command__Status* status)
436 {
437  if (status == NULL || !is_level_enabled(log_level)) {
438  return;
439  }
440 
441  ProtobufCMessage* protoMessage = &status->base;
443 
445  KineticLogger_LogPrintf(log_level, "Operation completed successfully\n");
446  }
448  KineticLogger_LogPrintf(log_level, "Operation was aborted!\n");
449  }
450  else {
451  // Output status code short name
452  const ProtobufCMessageDescriptor* protoMessageDescriptor = protoMessage->descriptor;
453  const ProtobufCFieldDescriptor* statusCodeDescriptor =
454  protobuf_c_message_descriptor_get_field_by_name(protoMessageDescriptor, "code");
455  const ProtobufCEnumDescriptor* statusCodeEnumDescriptor =
456  (ProtobufCEnumDescriptor*)statusCodeDescriptor->descriptor;
457  const ProtobufCEnumValue* eStatusCodeVal =
458  protobuf_c_enum_descriptor_get_value(statusCodeEnumDescriptor, code);
459  KineticLogger_LogPrintf(log_level, "Operation completed but failed w/error: %s=%d(%s)\n",
460  statusCodeDescriptor->name, code, eStatusCodeVal->name);
461 
462  // Output status message, if supplied
463  if (status->statusmessage) {
464  const ProtobufCFieldDescriptor* statusMsgFieldDescriptor =
465  protobuf_c_message_descriptor_get_field_by_name(protoMessageDescriptor, "statusMessage");
466  const ProtobufCMessageDescriptor* statusMsgDescriptor =
467  (ProtobufCMessageDescriptor*)statusMsgFieldDescriptor->descriptor;
468 
469  KineticLogger_LogPrintf(log_level, " %s: '%s'", statusMsgDescriptor->name, status->statusmessage);
470  }
471 
472  // Output detailed message, if supplied
473  if (status->has_detailedmessage) {
474  char tmp[8], msg[256];
475  const ProtobufCFieldDescriptor* statusDetailedMsgFieldDescriptor =
476  protobuf_c_message_descriptor_get_field_by_name(
477  protoMessageDescriptor, "detailedMessage");
478  const ProtobufCMessageDescriptor* statusDetailedMsgDescriptor =
479  (ProtobufCMessageDescriptor*)
480  statusDetailedMsgFieldDescriptor->descriptor;
481 
482  sprintf(msg, " %s: ", statusDetailedMsgDescriptor->name);
483  for (size_t i = 0; i < status->detailedmessage.len; i++) {
484  sprintf(tmp, "%02hhX", status->detailedmessage.data[i]);
485  strcat(msg, tmp);
486  }
487  KineticLogger_LogPrintf(log_level, " %s", msg);
488  }
489  }
490 }
491 
492 void KineticLogger_LogByteArray(int log_level, const char* title, ByteArray bytes)
493 {
494  if (title == NULL || !is_level_enabled(log_level)) {
495  return;
496  }
497 
498  if (bytes.data == NULL) {
499  KineticLogger_LogPrintf(log_level, "%s: (??? bytes : buffer is NULL)", title);
500  return;
501  }
502  if (bytes.data == NULL) {
503  KineticLogger_LogPrintf(log_level, "%s: (0 bytes)", title);
504  return;
505  }
506  KineticLogger_LogPrintf(log_level, "%s: (%zd bytes)", title, bytes.len);
507  const int byteChars = 4;
508  const int bytesPerLine = 32;
509  const int lineLen = 4 + (bytesPerLine * byteChars);
510  char hex[lineLen + 1];
511  char ascii[lineLen + 1];
512  for (size_t i = 0; i < bytes.len;) {
513  hex[0] = '\0';
514  ascii[0] = '\0';
515  for (int j = 0;
516  j < bytesPerLine && i < bytes.len;
517  j++, i++) {
518  char byHex[8];
519  sprintf(byHex, "%02hhX", bytes.data[i]);
520  strcat(hex, byHex);
521  char byAscii[8];
522  int ch = (int)bytes.data[i];
523  if (ch >= 32 && ch <= 126) {
524  sprintf(byAscii, "%c", bytes.data[i]);
525  }
526  else {
527  byAscii[0] = '.';
528  byAscii[1] = '\0';
529  }
530  strcat(ascii, byAscii);
531  }
532  KineticLogger_LogPrintf(log_level, "%s: %s : %s", title, hex, ascii);
533  }
534 }
535 
536 void KineticLogger_LogByteBuffer(int log_level, const char* title, ByteBuffer buffer)
537 {
538  if (title == NULL || !is_level_enabled(log_level)) {
539  return;
540  }
541  ByteArray array = {.data = buffer.array.data, .len = buffer.bytesUsed};
542  KineticLogger_LogByteArray(log_level, title, array);
543 }
544 
545 //------------------------------------------------------------------------------
546 // Private Method Definitions
547 
548 static inline bool is_level_enabled(int log_level)
549 {
550  return (log_level <= KineticLogLevel && KineticLogLevel >= 0);
551 }
552 
553 static inline void lock_buffer(void)
554 {
555  pthread_mutex_lock(&BufferMutex);
556 }
557 
558 static inline void unlock_buffer()
559 {
560  pthread_mutex_unlock(&BufferMutex);
561 }
562 
563 static void flush_buffer(void)
564 {
565  fprintf(KineticLoggerHandle, "%s", Buffer);
566  fflush(KineticLoggerHandle);
567 }
568 
569 static inline char* get_buffer()
570 {
571  lock_buffer();
572  return Buffer;
573 }
574 
575 static inline void finish_buffer(void)
576 {
577  flush_buffer();
578  unlock_buffer();
579 }
#define KINETIC_C_VERSION
Structure for handling generic arrays of bytes.
Definition: byte_array.h:34
void KineticLogger_LogHeader(int log_level, const KineticPDUHeader *header)
static void flush_buffer(void)
Structure for an embedded ByteArray as a buffer.
Definition: byte_array.h:53
void KineticLogger_LogStatus(int log_level, Com__Seagate__Kinetic__Proto__Command__Status *status)
static void unlock_buffer(void)
static int indent_overflow
static char indent[64]
static FILE * KineticLoggerHandle
static char Buffer[1024]
static int KineticLogLevel
static void log_proto_level_start_array(const char *name, unsigned quantity)
static void log_version_info(void)
Com__Seagate__Kinetic__Proto__Command * com__seagate__kinetic__proto__command__unpack(ProtobufCAllocator *allocator, size_t len, const uint8_t *data)
Definition: kinetic.pb-c.c:268
ByteArray array
ByteArray holding allocated array w/length = allocated size.
Definition: byte_array.h:54
int KineticLogger_ByteArraySliceToCString(char *p_buf, const ByteArray bytes, const int start, const int count)
static void lock_buffer(void)
#define BUFFER_SIZE
#define BOOL_TO_STRING(_bool)
static void log_proto_level_start(const char *name)
#define LOG_INDENT
#define KINETIC_ASSERT(cond)
void KineticLogger_LogByteBuffer(int log_level, const char *title, ByteBuffer buffer)
static int bytetoa(char *p_buf, uint8_t val)
void KineticLogger_LogLocation(const char *filename, int line, const char *message)
static void log_proto_level_end_array(void)
size_t len
Number of bytes in the data field.
Definition: byte_array.h:35
#define STATIC
static void LogUnboxed(int log_level, void const *const fieldData, ProtobufCFieldDescriptor const *const fieldDesc, size_t const i, char *log_indent)
static const size_t max_indent
#define BUFFER_MAX_STRLEN
uint8_t * data
Pointer to an allocated array of data bytes.
Definition: byte_array.h:36
static char * get_buffer(void)
void KineticLogger_LogProtobuf(int log_level, const Com__Seagate__Kinetic__Proto__Message *msg)
#define KINETIC_C_REPO_HASH
void KineticLogger_LogByteArray(int log_level, const char *title, ByteArray bytes)
static void finish_buffer(void)
void KineticLogger_Close(void)
void KineticLogger_LogPrintf(int log_level, const char *format,...)
#define KINETIC_C_PROTOCOL_VERSION
size_t bytesUsed
Reflects the number of bytes used from the array
Definition: byte_array.h:55
static void log_proto_level_end(void)
Com__Seagate__Kinetic__Proto__Command__Status__StatusCode
Definition: kinetic.pb-c.h:78
void KineticLogger_Log(int log_level, const char *message)
static pthread_mutex_t BufferMutex
void com__seagate__kinetic__proto__command__free_unpacked(Com__Seagate__Kinetic__Proto__Command *message, ProtobufCAllocator *allocator)
Definition: kinetic.pb-c.c:277
static bool is_level_enabled(int log_level)
void KineticLogger_Init(const char *log_file, int log_level)
static void log_protobuf_message(int log_level, const ProtobufCMessage *msg, char *indent)