sotp_log.c

00001 /*
00002  * Copyright (c) 2016 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 
00017 // ----------------------------------------------------------- Includes -----------------------------------------------------------
00018 
00019 
00020 #include "pal.h"
00021 #include <string.h>
00022 #include <stdio.h>
00023 #include <stdarg.h>
00024 #include "sotp_log.h"
00025 
00026 #if SOTP_LOG
00027 
00028 #define LINE_SIZE 1024
00029 typedef struct {
00030     uint64_t start_time;
00031     uint64_t end_time;
00032     uint32_t action_id;
00033     uint32_t dummy;
00034     char line[LINE_SIZE];
00035 } sotp_log_entry_t;
00036 
00037 #define MAX_ENTRIES 64
00038 typedef struct {
00039     uint32_t num_entries;
00040     uint32_t curr_entry_ind;
00041     uint32_t ind_stack_ptr;
00042     uint32_t ind_stack[4];
00043     sotp_log_entry_t entries[MAX_ENTRIES];
00044 } sotp_thr_log_t;
00045 
00046 // Must be aligned to the size of native integer, otherwise atomic add may not work
00047 static uint32_t action_id_ctr  __attribute__((aligned(8)));
00048 #define MAX_NUMBER_OF_THREADS 9
00049 static sotp_thr_log_t thr_logs[MAX_NUMBER_OF_THREADS];
00050 
00051 // Initialize SOTP logs.
00052 // Parameters :
00053 // Return   : None.
00054 void sotp_log_init(void)
00055 {
00056     action_id_ctr = 0;
00057     memset(thr_logs, 0, sizeof(thr_logs));
00058 }
00059 
00060 // Create an SOTP log entry.
00061 // Parameters :
00062 // args     - [IN]   format (as in printf).
00063 // args     - [IN]   arg list (as in printf) to log.
00064 // Return   : None.
00065 void sotp_log_create(char *fmt, ...)
00066 {
00067     int thr = 0;
00068     sotp_thr_log_t *thr_log = &thr_logs[thr];
00069     sotp_log_entry_t *entry;
00070     uint32_t entry_ind;
00071     va_list args;
00072     uint32_t action_id;
00073 
00074     action_id = pal_osAtomicIncrement((int32_t *) &action_id_ctr, 1);
00075 
00076     if (thr_log->num_entries < MAX_ENTRIES) {
00077         thr_log->num_entries++;
00078     }
00079 
00080     entry_ind = thr_log->curr_entry_ind;
00081     thr_logs->ind_stack[thr_logs->ind_stack_ptr++] = entry_ind;
00082     thr_log->curr_entry_ind = (thr_log->curr_entry_ind + 1) % MAX_ENTRIES;
00083     entry = &thr_log->entries[entry_ind];
00084     entry->start_time = pal_osKernelSysTick();
00085     entry->action_id = action_id;
00086 
00087     va_start(args, fmt);
00088     vsnprintf(entry->line, LINE_SIZE, fmt, args);
00089     va_end(args);
00090 }
00091 
00092 // Append to an SOTP log entry.
00093 // Parameters :
00094 // args     - [IN]   format (as in printf).
00095 // args     - [IN]   arg list (as in printf) to log.
00096 // Return   : None.
00097 void sotp_log_append(char *fmt, ...)
00098 {
00099     int thr = 0;
00100     sotp_thr_log_t *thr_log = &thr_logs[thr];
00101     sotp_log_entry_t *entry;
00102     uint32_t entry_ind;
00103     va_list args;
00104 
00105     if (!thr_logs->ind_stack_ptr) {
00106         return;
00107     }
00108 
00109     entry_ind = thr_logs->ind_stack[thr_logs->ind_stack_ptr-1];
00110     entry = &thr_log->entries[entry_ind];
00111     va_start(args, fmt);
00112     vsnprintf(entry->line + strlen(entry->line), LINE_SIZE-strlen(entry->line), fmt, args);
00113     va_end(args);
00114 
00115 }
00116 
00117 // Finalize an SOTP log entry.
00118 // Parameters :
00119 // Return   : None.
00120 void sotp_log_finalize(void)
00121 {
00122     int thr = 0;
00123     sotp_thr_log_t *thr_log = &thr_logs[thr];
00124     sotp_log_entry_t *entry;
00125     uint32_t entry_ind;
00126 
00127     if (!thr_logs->ind_stack_ptr) {
00128         return;
00129     }
00130     entry_ind = thr_logs->ind_stack[--thr_logs->ind_stack_ptr];
00131     entry = &thr_log->entries[entry_ind];
00132     entry->end_time = pal_osKernelSysTick();
00133 }
00134 
00135 // Print SOTP log (sorted by start time).
00136 // Parameters :
00137 // Return   : None.
00138 void sotp_log_print_log(void)
00139 {
00140     int pending_logs;
00141     int log_inds[MAX_NUMBER_OF_THREADS];
00142     int i, thr;
00143     uint64_t earliest;
00144     sotp_log_entry_t *curr_entry, *entry_to_print;
00145     uint64_t ref_time;
00146 
00147     pending_logs = 0;
00148     ref_time = (uint64_t) -1;
00149     for (i = 0; i < MAX_NUMBER_OF_THREADS; i++) {
00150         if (!thr_logs[i].num_entries) {
00151             log_inds[i] = -1;
00152             continue;
00153         }
00154         pending_logs++;
00155         if (thr_logs[i].num_entries < MAX_ENTRIES)
00156             log_inds[i] = 0;
00157         else
00158             log_inds[i] = thr_logs[i].curr_entry_ind;
00159         curr_entry = &thr_logs[i].entries[log_inds[i]];
00160         if (curr_entry->start_time && (curr_entry->start_time < ref_time)) {
00161             ref_time = curr_entry->start_time;
00162         }
00163     }
00164 
00165     while (pending_logs) {
00166         earliest = (uint64_t) -1;
00167         for (i = 0; i < MAX_NUMBER_OF_THREADS; i++) {
00168             if (log_inds[i] < 0)
00169                 continue;
00170             curr_entry = &thr_logs[i].entries[log_inds[i]];
00171             if (curr_entry->start_time < earliest) {
00172                 entry_to_print = curr_entry;
00173                 earliest = curr_entry->start_time;
00174                 thr = i;
00175             }
00176         }
00177         printf("%d (+%9ld-%9ld) #%9d %s\n",
00178                 thr,
00179                 entry_to_print->start_time - ref_time,
00180                 entry_to_print->end_time?(entry_to_print->end_time - entry_to_print->start_time) : 0,
00181                 entry_to_print->action_id,
00182                 entry_to_print->line);
00183         ref_time = entry_to_print->start_time;
00184         log_inds[thr] = (log_inds[thr] + 1) % MAX_ENTRIES;
00185         if (log_inds[thr] == thr_logs[thr].curr_entry_ind) {
00186             log_inds[thr] = -1;
00187             pending_logs--;
00188         }
00189     }
00190 }
00191 
00192 #endif