mbed_trace.c

00001 /*
00002  * Copyright (c) 2014-2015 ARM Limited. All rights reserved.
00003  * SPDX-License-Identifier: Apache-2.0
00004  * Licensed under the Apache License, Version 2.0 (the License); you may
00005  * not use this file except in compliance with the License.
00006  * You may obtain a copy of the License at
00007  *
00008  * http://www.apache.org/licenses/LICENSE-2.0
00009  *
00010  * Unless required by applicable law or agreed to in writing, software
00011  * distributed under the License is distributed on an AS IS BASIS, WITHOUT
00012  * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
00013  * See the License for the specific language governing permissions and
00014  * limitations under the License.
00015  */
00016 #include <stdio.h>
00017 #include <string.h>
00018 #include <stdarg.h>
00019 
00020 #ifndef YOTTA_CFG_MBED_TRACE
00021 #define YOTTA_CFG_MBED_TRACE 1
00022 #define YOTTA_CFG_MBED_TRACE_FEA_IPV6 1
00023 #endif
00024 
00025 #include "mbed-trace/mbed_trace.h"
00026 #if YOTTA_CFG_MBED_TRACE_FEA_IPV6 == 1
00027 #include "mbed-client-libservice/ip6string.h"
00028 #include "mbed-client-libservice/common_functions.h"
00029 #endif
00030 
00031 #if defined(YOTTA_CFG_MBED_TRACE_MEM)
00032 #define MBED_TRACE_MEM_INCLUDE      YOTTA_CFG_MBED_TRACE_MEM_INCLUDE
00033 #define MBED_TRACE_MEM_ALLOC        YOTTA_CFG_MBED_TRACE_MEM_ALLOC
00034 #define MBED_TRACE_MEM_FREE         YOTTA_CFG_MBED_TRACE_MEM_FREE
00035 #else /* YOTTA_CFG_MEMLIB */
00036 // Default options
00037 #ifndef MBED_TRACE_MEM_INCLUDE
00038 #define MBED_TRACE_MEM_INCLUDE   <stdlib.h>
00039 #endif
00040 #include MBED_TRACE_MEM_INCLUDE
00041 #ifndef MBED_TRACE_MEM_ALLOC
00042 #define MBED_TRACE_MEM_ALLOC malloc
00043 #endif
00044 #ifndef MBED_TRACE_MEM_FREE
00045 #define MBED_TRACE_MEM_FREE  free
00046 #endif
00047 #endif /* YOTTA_CFG_MEMLIB */
00048 
00049 #define VT100_COLOR_ERROR "\x1b[31m"
00050 #define VT100_COLOR_WARN  "\x1b[33m"
00051 #define VT100_COLOR_INFO  "\x1b[39m"
00052 #define VT100_COLOR_DEBUG "\x1b[90m"
00053 
00054 /** default max trace line size in bytes */
00055 #ifdef YOTTA_CFG_MBED_TRACE_LINE_LENGTH
00056 #define DEFAULT_TRACE_LINE_LENGTH         YOTTA_CFG_MBED_TRACE_LINE_LENGTH
00057 #else
00058 #define DEFAULT_TRACE_LINE_LENGTH         1024
00059 #endif
00060 /** default max temporary buffer size in bytes, used in
00061     trace_ipv6, trace_ipv6_prefix and trace_array */
00062 #ifdef YOTTA_CFG_MBED_TRACE_TMP_LINE_LEN
00063 #define DEFAULT_TRACE_TMP_LINE_LEN        YOTTA_CFG_MBED_TRACE_TMP_LINE_LEN
00064 #elif defined YOTTA_CFG_MTRACE_TMP_LINE_LEN
00065 #warning The YOTTA_CFG_MTRACE_TMP_LINE_LEN flag is deprecated! Use YOTTA_CFG_MBED_TRACE_TMP_LINE_LEN instead.
00066 #define DEFAULT_TRACE_TMP_LINE_LEN        YOTTA_CFG_MTRACE_TMP_LINE_LEN
00067 #else
00068 #define DEFAULT_TRACE_TMP_LINE_LEN        128
00069 #endif
00070 /** default max filters (include/exclude) length in bytes */
00071 #define DEFAULT_TRACE_FILTER_LENGTH       24
00072 
00073 /** default print function, just redirect str to printf */
00074 static void mbed_trace_realloc( char **buffer, int *length_ptr, int new_length);
00075 static void mbed_trace_default_print(const char *str);
00076 static void mbed_trace_reset_tmp(void);
00077 
00078 typedef struct trace_s {
00079     /** trace configuration bits */
00080     uint8_t trace_config;
00081     /** exclude filters list, related group name */
00082     char *filters_exclude;
00083     /** include filters list, related group name */
00084     char *filters_include;
00085     /** Filters length */
00086     int filters_length;
00087     /** trace line */
00088     char *line;
00089     /** trace line length */
00090     int line_length;
00091     /** temporary data */
00092     char *tmp_data;
00093     /** temporary data array length */
00094     int tmp_data_length;
00095     /** temporary data pointer */
00096     char *tmp_data_ptr;
00097 
00098     /** prefix function, which can be used to put time to the trace line */
00099     char *(*prefix_f)(size_t);
00100     /** suffix function, which can be used to some string to the end of trace line */
00101     char *(*suffix_f)(void);
00102     /** print out function. Can be redirect to flash for example. */
00103     void (*printf)(const char *);
00104     /** print out function for TRACE_LEVEL_CMD */
00105     void (*cmd_printf)(const char *);
00106     /** mutex wait function which can be called to lock against a mutex. */
00107     void (*mutex_wait_f)(void);
00108     /** mutex release function which must be used to release the mutex locked by mutex_wait_f. */
00109     void (*mutex_release_f)(void);
00110     /** number of times the mutex has been locked */
00111     int mutex_lock_count;
00112 } trace_t;
00113 
00114 static trace_t m_trace = {
00115     .filters_exclude = 0,
00116     .filters_include = 0,
00117     .line = 0,
00118     .tmp_data = 0,
00119     .prefix_f = 0,
00120     .suffix_f = 0,
00121     .printf  = 0,
00122     .cmd_printf = 0,
00123     .mutex_wait_f = 0,
00124     .mutex_release_f = 0,
00125     .mutex_lock_count = 0
00126 };
00127 
00128 int mbed_trace_init(void)
00129 {
00130     m_trace.trace_config = TRACE_MODE_COLOR | TRACE_ACTIVE_LEVEL_ALL | TRACE_CARRIAGE_RETURN;
00131     m_trace.line_length = DEFAULT_TRACE_LINE_LENGTH;
00132     if (m_trace.line == NULL) {
00133         m_trace.line = MBED_TRACE_MEM_ALLOC(m_trace.line_length);
00134     }
00135     m_trace.tmp_data_length = DEFAULT_TRACE_TMP_LINE_LEN;
00136     if (m_trace.tmp_data == NULL) {
00137         m_trace.tmp_data = MBED_TRACE_MEM_ALLOC(m_trace.tmp_data_length);
00138     }
00139     m_trace.tmp_data_ptr = m_trace.tmp_data;
00140     m_trace.filters_length = DEFAULT_TRACE_FILTER_LENGTH;
00141     if (m_trace.filters_exclude == NULL) {
00142         m_trace.filters_exclude = MBED_TRACE_MEM_ALLOC(m_trace.filters_length);
00143     }
00144     if (m_trace.filters_include == NULL) {
00145         m_trace.filters_include = MBED_TRACE_MEM_ALLOC(m_trace.filters_length);
00146     }
00147 
00148     if (m_trace.line == NULL ||
00149             m_trace.tmp_data == NULL ||
00150             m_trace.filters_exclude == NULL  ||
00151             m_trace.filters_include == NULL) {
00152         //memory allocation fail
00153         mbed_trace_free();
00154         return -1;
00155     }
00156     memset(m_trace.tmp_data, 0, m_trace.tmp_data_length);
00157     memset(m_trace.filters_exclude, 0, m_trace.filters_length);
00158     memset(m_trace.filters_include, 0, m_trace.filters_length);
00159     memset(m_trace.line, 0, m_trace.line_length);
00160 
00161     m_trace.prefix_f = 0;
00162     m_trace.suffix_f = 0;
00163     m_trace.printf = mbed_trace_default_print;
00164     m_trace.cmd_printf = 0;
00165 
00166     return 0;
00167 }
00168 void mbed_trace_free(void)
00169 {
00170     MBED_TRACE_MEM_FREE(m_trace.line);
00171     m_trace.line_length = 0;
00172     m_trace.line = 0;
00173     MBED_TRACE_MEM_FREE(m_trace.tmp_data);
00174     m_trace.tmp_data = 0;
00175     m_trace.tmp_data_ptr = 0;
00176     MBED_TRACE_MEM_FREE(m_trace.filters_exclude);
00177     m_trace.filters_exclude = 0;
00178     MBED_TRACE_MEM_FREE(m_trace.filters_include);
00179     m_trace.filters_include = 0;
00180     m_trace.filters_length = 0;
00181     m_trace.prefix_f = 0;
00182     m_trace.suffix_f = 0;
00183     m_trace.printf = mbed_trace_default_print;
00184     m_trace.cmd_printf = 0;
00185     m_trace.mutex_wait_f = 0;
00186     m_trace.mutex_release_f = 0;
00187     m_trace.mutex_lock_count = 0;
00188 }
00189 static void mbed_trace_realloc( char **buffer, int *length_ptr, int new_length)
00190 {
00191     MBED_TRACE_MEM_FREE(*buffer);
00192     *buffer  = MBED_TRACE_MEM_ALLOC(new_length);
00193     *length_ptr = new_length;
00194 }
00195 void mbed_trace_buffer_sizes(int lineLength, int tmpLength)
00196 {
00197     if( lineLength > 0 ) {
00198         mbed_trace_realloc( &(m_trace.line), &m_trace.line_length, lineLength );
00199     }
00200     if( tmpLength > 0 ) {
00201         mbed_trace_realloc( &(m_trace.tmp_data), &m_trace.tmp_data_length, tmpLength);
00202         mbed_trace_reset_tmp();
00203     }
00204 }
00205 void mbed_trace_config_set(uint8_t config)
00206 {
00207     m_trace.trace_config = config;
00208 }
00209 uint8_t mbed_trace_config_get(void)
00210 {
00211     return m_trace.trace_config;
00212 }
00213 void mbed_trace_prefix_function_set(char *(*pref_f)(size_t))
00214 {
00215     m_trace.prefix_f = pref_f;
00216 }
00217 void mbed_trace_suffix_function_set(char *(*suffix_f)(void))
00218 {
00219     m_trace.suffix_f = suffix_f;
00220 }
00221 void mbed_trace_print_function_set(void (*printf)(const char *))
00222 {
00223     m_trace.printf = printf;
00224 }
00225 void mbed_trace_cmdprint_function_set(void (*printf)(const char *))
00226 {
00227     m_trace.cmd_printf = printf;
00228 }
00229 void mbed_trace_mutex_wait_function_set(void (*mutex_wait_f)(void))
00230 {
00231     m_trace.mutex_wait_f = mutex_wait_f;
00232 }
00233 void mbed_trace_mutex_release_function_set(void (*mutex_release_f)(void))
00234 {
00235     m_trace.mutex_release_f = mutex_release_f;
00236 }
00237 void mbed_trace_exclude_filters_set(char *filters)
00238 {
00239     if (filters) {
00240         (void)strncpy(m_trace.filters_exclude, filters, m_trace.filters_length);
00241     } else {
00242         m_trace.filters_exclude[0] = 0;
00243     }
00244 }
00245 const char *mbed_trace_exclude_filters_get(void)
00246 {
00247     return m_trace.filters_exclude;
00248 }
00249 const char *mbed_trace_include_filters_get(void)
00250 {
00251     return m_trace.filters_include;
00252 }
00253 void mbed_trace_include_filters_set(char *filters)
00254 {
00255     if (filters) {
00256         (void)strncpy(m_trace.filters_include, filters, m_trace.filters_length);
00257     } else {
00258         m_trace.filters_include[0] = 0;
00259     }
00260 }
00261 static int8_t mbed_trace_skip(int8_t dlevel, const char *grp)
00262 {
00263     if (dlevel >= 0 && grp != 0) {
00264         // filter debug prints only when dlevel is >0 and grp is given
00265 
00266         /// @TODO this could be much better..
00267         if (m_trace.filters_exclude[0] != '\0' &&
00268                 strstr(m_trace.filters_exclude, grp) != 0) {
00269             //grp was in exclude list
00270             return 1;
00271         }
00272         if (m_trace.filters_include[0] != '\0' &&
00273                 strstr(m_trace.filters_include, grp) == 0) {
00274             //grp was in include list
00275             return 1;
00276         }
00277     }
00278     return 0;
00279 }
00280 static void mbed_trace_default_print(const char *str)
00281 {
00282     puts(str);
00283 }
00284 void mbed_tracef(uint8_t dlevel, const char *grp, const char *fmt, ...)
00285 {
00286     va_list ap;
00287     va_start(ap, fmt);
00288     mbed_vtracef(dlevel, grp, fmt, ap);
00289     va_end(ap);
00290 }
00291 void mbed_vtracef(uint8_t dlevel, const char* grp, const char *fmt, va_list ap)
00292 {
00293     if ( m_trace.mutex_wait_f ) {
00294         m_trace.mutex_wait_f();
00295         m_trace.mutex_lock_count++;
00296     }
00297 
00298     if (NULL == m_trace.line) {
00299         goto end;
00300     }
00301 
00302     m_trace.line[0] = 0; //by default trace is empty
00303 
00304     if (mbed_trace_skip(dlevel, grp) || fmt == 0 || grp == 0 || !m_trace.printf) {
00305         //return tmp data pointer back to the beginning
00306         mbed_trace_reset_tmp();
00307         goto end;
00308     }
00309     if ((m_trace.trace_config & TRACE_MASK_LEVEL) &  dlevel) {
00310         bool color = (m_trace.trace_config & TRACE_MODE_COLOR) != 0;
00311         bool plain = (m_trace.trace_config & TRACE_MODE_PLAIN) != 0;
00312         bool cr    = (m_trace.trace_config & TRACE_CARRIAGE_RETURN) != 0;
00313 
00314         int retval = 0, bLeft = m_trace.line_length;
00315         char *ptr = m_trace.line;
00316         if (plain == true || dlevel == TRACE_LEVEL_CMD) {
00317             //add trace data
00318             retval = vsnprintf(ptr, bLeft, fmt, ap);
00319             if (dlevel == TRACE_LEVEL_CMD && m_trace.cmd_printf) {
00320                 m_trace.cmd_printf(m_trace.line);
00321                 m_trace.cmd_printf("\n");
00322             } else {
00323                 //print out whole data
00324                 m_trace.printf(m_trace.line);
00325             }
00326         } else {
00327             if (color) {
00328                 if (cr) {
00329                     retval = snprintf(ptr, bLeft, "\r\x1b[2K");
00330                     if (retval >= bLeft) {
00331                         retval = 0;
00332                     }
00333                     if (retval > 0) {
00334                         ptr += retval;
00335                         bLeft -= retval;
00336                     }
00337                 }
00338                 if (bLeft > 0) {
00339                     //include color in ANSI/VT100 escape code
00340                     switch (dlevel) {
00341                         case (TRACE_LEVEL_ERROR):
00342                             retval = snprintf(ptr, bLeft, "%s", VT100_COLOR_ERROR);
00343                             break;
00344                         case (TRACE_LEVEL_WARN):
00345                             retval = snprintf(ptr, bLeft, "%s", VT100_COLOR_WARN);
00346                             break;
00347                         case (TRACE_LEVEL_INFO):
00348                             retval = snprintf(ptr, bLeft, "%s", VT100_COLOR_INFO);
00349                             break;
00350                         case (TRACE_LEVEL_DEBUG):
00351                             retval = snprintf(ptr, bLeft, "%s", VT100_COLOR_DEBUG);
00352                             break;
00353                         default:
00354                             color = 0; //avoid unneeded color-terminate code
00355                             retval = 0;
00356                             break;
00357                     }
00358                     if (retval >= bLeft) {
00359                         retval = 0;
00360                     }
00361                     if (retval > 0 && color) {
00362                         ptr += retval;
00363                         bLeft -= retval;
00364                     }
00365                 }
00366 
00367             }
00368             if (bLeft > 0 && m_trace.prefix_f) {
00369                 //find out length of body
00370                 size_t sz = 0;
00371                 va_list ap2;
00372                 va_copy(ap2, ap);
00373                 sz = vsnprintf(NULL, 0, fmt, ap2) + retval + (retval ? 4 : 0);
00374                 va_end(ap2);
00375                 //add prefix string
00376                 retval = snprintf(ptr, bLeft, "%s", m_trace.prefix_f(sz));
00377                 if (retval >= bLeft) {
00378                     retval = 0;
00379                 }
00380                 if (retval > 0) {
00381                     ptr += retval;
00382                     bLeft -= retval;
00383                 }
00384             }
00385             if (bLeft > 0) {
00386                 //add group tag
00387                 switch (dlevel) {
00388                     case (TRACE_LEVEL_ERROR):
00389                         retval = snprintf(ptr, bLeft, "[ERR ][%-4s]: ", grp);
00390                         break;
00391                     case (TRACE_LEVEL_WARN):
00392                         retval = snprintf(ptr, bLeft, "[WARN][%-4s]: ", grp);
00393                         break;
00394                     case (TRACE_LEVEL_INFO):
00395                         retval = snprintf(ptr, bLeft, "[INFO][%-4s]: ", grp);
00396                         break;
00397                     case (TRACE_LEVEL_DEBUG):
00398                         retval = snprintf(ptr, bLeft, "[DBG ][%-4s]: ", grp);
00399                         break;
00400                     default:
00401                         retval = snprintf(ptr, bLeft, "              ");
00402                         break;
00403                 }
00404                 if (retval >= bLeft) {
00405                     retval = 0;
00406                 }
00407                 if (retval > 0) {
00408                     ptr += retval;
00409                     bLeft -= retval;
00410                 }
00411             }
00412             if (retval > 0 && bLeft > 0) {
00413                 //add trace text
00414                 retval = vsnprintf(ptr, bLeft, fmt, ap);
00415                 if (retval >= bLeft) {
00416                     retval = 0;
00417                 }
00418                 if (retval > 0) {
00419                     ptr += retval;
00420                     bLeft -= retval;
00421                 }
00422             }
00423 
00424             if (retval > 0 && bLeft > 0  && m_trace.suffix_f) {
00425                 //add suffix string
00426                 retval = snprintf(ptr, bLeft, "%s", m_trace.suffix_f());
00427                 if (retval >= bLeft) {
00428                     retval = 0;
00429                 }
00430                 if (retval > 0) {
00431                     ptr += retval;
00432                     bLeft -= retval;
00433                 }
00434             }
00435 
00436             if (retval > 0 && bLeft > 0  && color) {
00437                 //add zero color VT100 when color mode
00438                 retval = snprintf(ptr, bLeft, "\x1b[0m");
00439                 if (retval >= bLeft) {
00440                     retval = 0;
00441                 }
00442                 if (retval > 0) {
00443                     // not used anymore
00444                     //ptr += retval;
00445                     //bLeft -= retval;
00446                 }
00447             }
00448             //print out whole data
00449             m_trace.printf(m_trace.line);
00450         }
00451         //return tmp data pointer back to the beginning
00452         mbed_trace_reset_tmp();
00453     }
00454 
00455 end:
00456     if ( m_trace.mutex_release_f ) {
00457         // Store the mutex lock count to temp variable so that it won't get
00458         // clobbered during last loop iteration when mutex gets released
00459         int count = m_trace.mutex_lock_count;
00460         m_trace.mutex_lock_count = 0;
00461         // Since the helper functions (eg. mbed_trace_array) are used like this:
00462         //   mbed_tracef(TRACE_LEVEL_INFO, "grp", "%s", mbed_trace_array(some_array))
00463         // The helper function MUST acquire the mutex if it modifies any buffers. However
00464         // it CANNOT unlock the mutex because that would allow another thread to acquire
00465         // the mutex after helper function unlocks it and before mbed_tracef acquires it
00466         // for itself. This means that here we have to unlock the mutex as many times
00467         // as it was acquired by trace function and any possible helper functions.
00468         do {
00469             m_trace.mutex_release_f();
00470         } while (--count > 0);
00471     }
00472 }
00473 static void mbed_trace_reset_tmp(void)
00474 {
00475     m_trace.tmp_data_ptr = m_trace.tmp_data;
00476 }
00477 const char *mbed_trace_last(void)
00478 {
00479     return m_trace.line;
00480 }
00481 /* Helping functions */
00482 #define tmp_data_left()  m_trace.tmp_data_length-(m_trace.tmp_data_ptr-m_trace.tmp_data)
00483 #if YOTTA_CFG_MBED_TRACE_FEA_IPV6 == 1
00484 char *mbed_trace_ipv6(const void *addr_ptr)
00485 {
00486     /** Acquire mutex. It is released before returning from mbed_vtracef. */
00487     if ( m_trace.mutex_wait_f ) {
00488         m_trace.mutex_wait_f();
00489         m_trace.mutex_lock_count++;
00490     }
00491     char *str = m_trace.tmp_data_ptr;
00492     if (str == NULL) {
00493         return "";
00494     }
00495     if (tmp_data_left() < 41) {
00496         return "";
00497     }
00498     if (addr_ptr == NULL) {
00499         return "<null>";
00500     }
00501     str[0] = 0;
00502     m_trace.tmp_data_ptr += ip6tos(addr_ptr, str) + 1;
00503     return str;
00504 }
00505 char *mbed_trace_ipv6_prefix(const uint8_t *prefix, uint8_t prefix_len)
00506 {
00507     /** Acquire mutex. It is released before returning from mbed_vtracef. */
00508     if ( m_trace.mutex_wait_f ) {
00509         m_trace.mutex_wait_f();
00510         m_trace.mutex_lock_count++;
00511     }
00512     char *str = m_trace.tmp_data_ptr;
00513     if (str == NULL) {
00514         return "";
00515     }
00516     if (tmp_data_left() < 45) {
00517         return "";
00518     }
00519 
00520     if ((prefix_len != 0 && prefix == NULL) || prefix_len > 128) {
00521         return "<err>";
00522     }
00523 
00524     m_trace.tmp_data_ptr += ip6_prefix_tos(prefix, prefix_len, str) + 1;
00525     return str;
00526 }
00527 #endif //YOTTA_CFG_MBED_TRACE_FEA_IPV6
00528 char *mbed_trace_array(const uint8_t *buf, uint16_t len)
00529 {
00530     /** Acquire mutex. It is released before returning from mbed_vtracef. */
00531     if ( m_trace.mutex_wait_f ) {
00532         m_trace.mutex_wait_f();
00533         m_trace.mutex_lock_count++;
00534     }
00535     int i, bLeft = tmp_data_left();
00536     char *str, *wptr;
00537     str = m_trace.tmp_data_ptr;
00538     if (str == NULL || bLeft == 0) {
00539         return "";
00540     }
00541     if (buf == NULL) {
00542         return "<null>";
00543     }
00544     wptr = str;
00545     wptr[0] = 0;
00546     const uint8_t *ptr = buf;
00547     char overflow = 0;
00548     for (i = 0; i < len; i++) {
00549         if (bLeft <= 3) {
00550             overflow = 1;
00551             break;
00552         }
00553         int retval = snprintf(wptr, bLeft, "%02x:", *ptr++);
00554         if (retval <= 0 || retval > bLeft) {
00555             break;
00556         }
00557         bLeft -= retval;
00558         wptr += retval;
00559     }
00560     if (wptr > str) {
00561         if( overflow ) {
00562             // replace last character as 'star',
00563             // which indicate buffer len is not enough
00564             *(wptr - 1) = '*';
00565         } else {
00566             //null to replace last ':' character
00567             *(wptr - 1) = 0;
00568         }
00569     }
00570     m_trace.tmp_data_ptr = wptr;
00571     return str;
00572 }