cint_logger.h (20945B)
1 /* 2 * 3 * 4 * This license is set out in https://raw.githubusercontent.com/Broadcom-Network-Switching-Software/OpenBCM/master/Legal/LICENSE file. 5 * 6 * Copyright 2007-2019 Broadcom Inc. All rights reserved. 7 * 8 * File: cint_logger.h 9 * Purpose: CINT logger, see cint_logger.c 10 */ 11 12 #ifndef __CINT_LOGGER_H__ 13 #define __CINT_LOGGER_H__ 14 15 #if CINT_CONFIG_INCLUDE_CINT_LOGGER == 1 16 17 #include <shared/bitop.h> 18 #include <sal/core/sync.h> 19 #include <sal/core/thread.h> 20 #include "cint_config.h" 21 #include "cint_types.h" 22 23 /* 24 * Adds logger structures and variables definitions to the CINT interpreter 25 */ 26 extern void cint_logger_cint_init(void); 27 28 /* 29 * Fetches the per-thread data maintained by the logger 30 */ 31 extern void* cint_logger_thread_specific(void); 32 33 /* 34 * Logger top-level function - invoked from BCM dispatch.c 35 */ 36 extern void cint_log_function_arguments (const char *fn, void **api_params, unsigned int flags, int call_id, void *arg_ptrs[], int *skip_dispatch); 37 38 /* 39 * API behind CINT_LOGGER_SET_CALLER_CONTEXT macro application can use to 40 * indicate the FILE, LINE and FUNCTION from which an API is invoked 41 */ 42 extern void cint_logger_set_caller_context (const char *f, int l, const char *F); 43 44 /* 45 * CINT internal routine to fetch system timestamp in usec resolution 46 */ 47 extern unsigned long cint_timer_get(void); 48 49 static inline void cint_logger_update_arg_ptrs (void *arg_ptrs[], int nargs, ...) 50 { 51 int i; 52 va_list ap; 53 54 va_start(ap, nargs); 55 56 for (i = 0; i < nargs; i++) { 57 arg_ptrs[i] = va_arg(ap, void*); 58 } 59 60 va_end(ap); 61 } 62 63 /* 64 * structure to hold related run-time statistics for any given object together 65 */ 66 typedef struct cint_logger_rtime_s { 67 68 /* 69 * the last run-time computed 70 */ 71 unsigned int last; 72 73 /* 74 * minimum run-time measurement so far 75 */ 76 unsigned int min; 77 78 /* 79 * maximum run-time measurement so far 80 */ 81 unsigned int max; 82 83 /* 84 * average of all run-times measured so far 85 */ 86 unsigned int avg; 87 88 } cint_logger_rtime_t; 89 90 /* 91 * Initialize a run-time structure. Mainly set min to something large. 92 */ 93 #define CINT_LOGGER_INIT_RTIME_T(s) \ 94 { \ 95 (s).last = 0; \ 96 (s).min = ~0x0; \ 97 (s).max = 0; \ 98 (s).avg = 0; \ 99 } 100 101 /* 102 * enum for all the logger modes 103 */ 104 typedef enum { 105 106 /* 107 * preload or cache the CINT data 108 */ 109 cintLoggerModePreload, 110 111 /* 112 * log API calls to BSL layer and source 113 */ 114 cintLoggerModeLog, 115 116 /* 117 * only cache API call data into memory 118 */ 119 cintLoggerModeCache, 120 121 /* 122 * replaying previously generated logs, expected to be used on SVK 123 */ 124 cintLoggerModeReplay, 125 126 } cint_logger_mode_t; 127 128 /* 129 * structure for per API cached data 130 */ 131 typedef struct cint_logger_api_params_s { 132 133 /* 134 * prev and next pointers for building a link list of cached data 135 */ 136 void *next, *prev; 137 138 /* 139 * API for which this cache was created 140 */ 141 char *fn; 142 143 /* 144 * CINT parameters data for the API 145 */ 146 cint_parameter_desc_t *params; 147 148 /* 149 * sizes of the basetypes of each parameter 150 */ 151 int basetype_size[CINT_CONFIG_MAX_FPARAMS+1]; 152 153 /* 154 * whether the basetype is an array (i.e. typedef) 155 */ 156 SHR_BITDCLNAME(is_basetype_arr, CINT_CONFIG_MAX_FPARAMS+1); 157 158 /* 159 * whether the parameter is a char pointer 160 */ 161 SHR_BITDCLNAME(is_charptr, CINT_CONFIG_MAX_FPARAMS+1); 162 163 /* 164 * number of API arguments +1 (return value) 165 */ 166 int nargs; 167 168 /* 169 * number of times the API was invoked 170 */ 171 int called_count; 172 173 /* 174 * run-time data for loading the argument pointer array 175 */ 176 cint_logger_rtime_t arg_ptrs; 177 178 /* 179 * run-time data for the preload phase of this API 180 */ 181 cint_logger_rtime_t preload; 182 183 /* 184 * run-time data for the before-dispatch logging for this API 185 */ 186 cint_logger_rtime_t call1; 187 188 /* 189 * run-time data for the dispatch routine for this API 190 */ 191 cint_logger_rtime_t dispatch; 192 193 /* 194 * run-time data for the after-dispatch logging for this API 195 */ 196 cint_logger_rtime_t call2; 197 198 /* 199 * total run-time data for the API 200 */ 201 cint_logger_rtime_t total; 202 203 } cint_logger_api_params_t; 204 205 /* 206 * Initialize the cached data structure for an API. Mainly the run-time data. 207 */ 208 #define CINT_LOGGER_INIT_API_PARAMS_T(p) \ 209 { \ 210 CINT_MEMSET((p), 0, sizeof(*(p))); \ 211 CINT_LOGGER_INIT_RTIME_T((p)->arg_ptrs); \ 212 CINT_LOGGER_INIT_RTIME_T((p)->preload); \ 213 CINT_LOGGER_INIT_RTIME_T((p)->call1); \ 214 CINT_LOGGER_INIT_RTIME_T((p)->dispatch); \ 215 CINT_LOGGER_INIT_RTIME_T((p)->call2); \ 216 CINT_LOGGER_INIT_RTIME_T((p)->total); \ 217 } 218 219 /* 220 * structure for per-thread logger data 221 */ 222 typedef struct cint_logger_thread_data_s { 223 224 /* 225 * whether logging is disabled for this thread 226 */ 227 int disabled; 228 229 /* 230 * whether logging is in progress for this thread 231 */ 232 int logger_is_active; 233 234 /* 235 * application is reponsible for indicating the following three to the 236 * logger accurately. This information will help to reconstruct the 237 * structure of the application code. 238 * Respectively the FILE, LINE and FUNCTION from where the API was invoked 239 */ 240 const char *caller_file; 241 int caller_line; 242 const char *caller_func; 243 244 } cint_logger_thread_data_t; 245 246 /* 247 * structure holding the data relevant for a call to the API 248 */ 249 typedef struct cint_logger_call_ctxt_s { 250 251 /* 252 * API to which this context belongs 253 */ 254 char *api; 255 256 /* 257 * flags with which the top-level logger routine was called 258 */ 259 unsigned int flags; 260 261 /* 262 * thread_id of the caller. 263 */ 264 sal_thread_t caller_tid; 265 266 /* 267 * name of the calling thread 268 */ 269 const char *caller_tname; 270 271 /* 272 * application FILE from which the API was called 273 */ 274 const char *caller_file; 275 276 /* 277 * LINE in FILE from which the API was called 278 */ 279 int caller_line; 280 281 /* 282 * allocation FUNCTION from which the API was called 283 */ 284 const char *caller_function; 285 286 /* 287 * pointer to the skip_dispatch boolean 288 */ 289 int *skip_dispatch; 290 291 /* 292 * block-ID - generally a counter incremented at each call 293 */ 294 int call_id; 295 296 } cint_logger_call_ctxt_t; 297 298 typedef int (*cint_logger_user_filter_cb_t)(cint_logger_thread_data_t*, cint_logger_call_ctxt_t*, cint_logger_api_params_t*, void * []); 299 300 /* 301 * structure to hold the global configuration data for the logger 302 */ 303 typedef struct cint_logger_global_cfg_data_s { 304 305 /* 306 * whether the logger is enabled? 307 */ 308 int enabled; 309 310 /* 311 * logger mode 312 */ 313 cint_logger_mode_t mode; 314 315 /* 316 * BSL layer from which logs will be sent 317 */ 318 bsl_layer_t logLayer; 319 320 /* 321 * BSL source from which logs will be sent 322 */ 323 bsl_source_t logSource; 324 325 /* 326 * name of the CINT function which will serve as a filter for the logger 327 */ 328 char *cint_filter_fn; 329 330 /* 331 * callback function provided by the application 332 */ 333 cint_logger_user_filter_cb_t user_filter_cb; 334 335 /* 336 */ 337 sal_tls_key_t *tls_key; 338 339 /* 340 * logger mutex 341 */ 342 sal_mutex_t mutex; 343 344 /* 345 * head of the list of API parameters 346 */ 347 cint_logger_api_params_t *ctxt_head; 348 349 /* 350 * running counter which serves as block-id in the logs 351 */ 352 int count; 353 354 /* 355 * the base indent level in terms of prefixed spaces when generating logs 356 */ 357 int base_indent; 358 359 /* 360 * parameters for the logging to file 361 */ 362 int log_to_file; 363 char *logfile; 364 void *logfile_fp; 365 366 } cint_logger_global_cfg_data_t; 367 368 extern cint_logger_global_cfg_data_t cint_logger_cfg; 369 #define CINT_LOGGER_LOCK sal_mutex_take(cint_logger_cfg.mutex, sal_mutex_FOREVER) 370 #define CINT_LOGGER_UNLOCK sal_mutex_give(cint_logger_cfg.mutex) 371 372 373 #define UPDATE_AVG_MIN_MAX(sp, item) \ 374 { \ 375 unsigned long long total; \ 376 total = (sp.item.avg * sp.called_count + sp.item.last); \ 377 sp.item.avg = total / (sp.called_count + 1); \ 378 if (sp.item.last > sp.item.max) { \ 379 sp.item.max = sp.item.last; \ 380 } \ 381 if (sp.item.last < sp.item.min) { \ 382 sp.item.min = sp.item.last; \ 383 } \ 384 } 385 386 #define UPDATE_ARG_PTRS(...) \ 387 cint_logger_update_arg_ptrs(&arg_ptrs[1], nargs, ## __VA_ARGS__) 388 389 #define CINT_LOGGER_CALL_DISPATCH(ret, f_api, args, n_args, args_by_ref) \ 390 do { \ 391 static cint_logger_api_params_t *api_params = NULL; \ 392 void *arg_ptrs[CINT_CONFIG_MAX_FPARAMS+1] = { &ret, }; \ 393 int nargs = n_args; \ 394 int skip_dispatch = 0; \ 395 unsigned long total_t1 = 0, total_t2 = 0; \ 396 unsigned long arg_ptrs_t1 = 0, arg_ptrs_t2 = 0; \ 397 unsigned long preload_t1 = 0, preload_t2 = 0; \ 398 unsigned long call1_t1 = 0, call1_t2 = 0; \ 399 unsigned long dispatch_t1 = 0, dispatch_t2 = 0; \ 400 unsigned long call2_t1 = 0, call2_t2 = 0; \ 401 int call_id = 0; \ 402 \ 403 \ 404 total_t1 = cint_timer_get(); \ 405 \ 406 preload_t1 = cint_timer_get(); \ 407 if (!api_params) { \ 408 /* \ 409 * Preload: initialize the CINT infrastructure if not yet done, query and cache the CINT parameter description \ 410 * for use by successive invocations of the API. Separated as a step by itself so that preload can be done \ 411 * for any/all APIs before actual API calls begin, maybe as part of the application init sequence \ 412 */ \ 413 cint_log_function_arguments(__FUNCTION__, (void**)&api_params, CINT_PARAM_IDX, \ 414 call_id, arg_ptrs, &skip_dispatch); \ 415 } \ 416 preload_t2 = cint_timer_get(); \ 417 \ 418 CINT_LOGGER_LOCK; \ 419 \ 420 cint_logger_cfg.count++; \ 421 call_id = cint_logger_cfg.count; \ 422 \ 423 CINT_LOGGER_UNLOCK; \ 424 \ 425 if (cint_logger_cfg.mode == cintLoggerModePreload) { \ 426 goto store_stats; \ 427 } \ 428 \ 429 arg_ptrs_t1 = cint_timer_get(); \ 430 UPDATE_ARG_PTRS args_by_ref; \ 431 arg_ptrs_t2 = cint_timer_get(); \ 432 \ 433 /* \ 434 * Before Dispatch: Log arguments before the dispatch routine is called \ 435 */ \ 436 skip_dispatch = 0; \ 437 call1_t1 = cint_timer_get(); \ 438 cint_log_function_arguments(__FUNCTION__, (void**)&api_params, CINT_PARAM_IN, \ 439 call_id, arg_ptrs, &skip_dispatch); \ 440 call1_t2 = cint_timer_get(); \ 441 \ 442 /* \ 443 * skip_dispatch may be used by the filter routine to render an API call ineffective. The filter routine has \ 444 * access to the ret value variable and can write desired value into it when skipping the dispatch routine \ 445 */ \ 446 if (!skip_dispatch) { \ 447 dispatch_t1 = cint_timer_get(); \ 448 ret = f_api args; \ 449 dispatch_t2 = cint_timer_get(); \ 450 } \ 451 \ 452 /* \ 453 * After Dispatch: Log arguments After the dispatch routine is called. This will log the return value and \ 454 * any values output by the dispatch routing. \ 455 */ \ 456 call2_t1 = cint_timer_get(); \ 457 cint_log_function_arguments(__FUNCTION__, (void**)&api_params, CINT_PARAM_OUT, \ 458 call_id, arg_ptrs, &skip_dispatch); \ 459 call2_t2 = cint_timer_get(); \ 460 \ 461 total_t2 = cint_timer_get(); \ 462 \ 463 store_stats: \ 464 \ 465 if (api_params) { \ 466 \ 467 CINT_LOGGER_LOCK; \ 468 \ 469 (*api_params).arg_ptrs.last = arg_ptrs_t2 - arg_ptrs_t1 ; \ 470 (*api_params).preload.last = preload_t2 - preload_t1 ; \ 471 (*api_params).call1.last = call1_t2 - call1_t1 ; \ 472 (*api_params).dispatch.last = dispatch_t2 - dispatch_t1 ; \ 473 (*api_params).call2.last = call2_t2 - call2_t1 ; \ 474 (*api_params).total.last = total_t2 - total_t1 ; \ 475 UPDATE_AVG_MIN_MAX((*api_params) , arg_ptrs); \ 476 UPDATE_AVG_MIN_MAX((*api_params) , preload ); \ 477 UPDATE_AVG_MIN_MAX((*api_params) , call1 ); \ 478 UPDATE_AVG_MIN_MAX((*api_params) , dispatch); \ 479 UPDATE_AVG_MIN_MAX((*api_params) , call2 ); \ 480 UPDATE_AVG_MIN_MAX((*api_params) , total ); \ 481 (*api_params).called_count++; \ 482 \ 483 CINT_LOGGER_UNLOCK; \ 484 \ 485 } \ 486 \ 487 } while(0) 488 489 #define CINT_LOGGER_SET_CALLER_CONTEXT(f,l,F) \ 490 cint_logger_set_caller_context(f,l,F) 491 492 #else 493 494 #define CINT_LOGGER_CALL_DISPATCH(ret, f_api, args, n_args, args_by_ref) ret = f_api args 495 496 #define CINT_LOGGER_SET_CALLER_CONTEXT(f,l,F) 497 498 #endif 499 500 #endif