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 = pal_osThreadGetId();
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 = pal_osThreadGetId();
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 // Finalize an SOTP log entry.
00117 // Parameters :
00118 // Return   : None.
00119 void sotp_log_finalize(void)
00120 {
00121     int thr = pal_osThreadGetId();
00122     sotp_thr_log_t *thr_log = &thr_logs[thr];
00123     sotp_log_entry_t *entry;
00124     uint32_t entry_ind;
00125 
00126     if (!thr_logs->ind_stack_ptr) {
00127         return;
00128     }
00129     entry_ind = thr_logs->ind_stack[--thr_logs->ind_stack_ptr];
00130     entry = &thr_log->entries[entry_ind];
00131     entry->end_time = pal_osKernelSysTick();
00132 }
00133 
00134 // Print SOTP log (sorted by start time).
00135 // Parameters :
00136 // Return   : None.
00137 void sotp_log_print_log(void)
00138 {
00139     int pending_logs;
00140     int log_inds[MAX_NUMBER_OF_THREADS];
00141     int i, thr;
00142     uint64_t earliest;
00143     sotp_log_entry_t *curr_entry, *entry_to_print;
00144     uint64_t ref_time;
00145 
00146     pending_logs = 0;
00147     ref_time = (uint64_t) -1;
00148     for (i = 0; i < MAX_NUMBER_OF_THREADS; i++) {
00149         if (!thr_logs[i].num_entries) {
00150             log_inds[i] = -1;
00151             continue;
00152         }
00153         pending_logs++;
00154         if (thr_logs[i].num_entries < MAX_ENTRIES)
00155             log_inds[i] = 0;
00156         else
00157             log_inds[i] = thr_logs[i].curr_entry_ind;
00158         curr_entry = &thr_logs[i].entries[log_inds[i]];
00159         if (curr_entry->start_time && (curr_entry->start_time < ref_time)) {
00160             ref_time = curr_entry->start_time;
00161         }
00162     }
00163 
00164     while (pending_logs) {
00165         earliest = (uint64_t) -1;
00166         for (i = 0; i < MAX_NUMBER_OF_THREADS; i++) {
00167             if (log_inds[i] < 0)
00168                 continue;
00169             curr_entry = &thr_logs[i].entries[log_inds[i]];
00170             if (curr_entry->start_time < earliest) {
00171                 entry_to_print = curr_entry;
00172                 earliest = curr_entry->start_time;
00173                 thr = i;
00174             }
00175         }
00176         printf("%d (+%9ld-%9ld) #%9d %s\n",
00177                 thr,
00178                 entry_to_print->start_time - ref_time,
00179                 entry_to_print->end_time?(entry_to_print->end_time - entry_to_print->start_time) : 0,
00180                 entry_to_print->action_id,
00181                 entry_to_print->line);
00182         ref_time = entry_to_print->start_time;
00183         log_inds[thr] = (log_inds[thr] + 1) % MAX_ENTRIES;
00184         if (log_inds[thr] == thr_logs[thr].curr_entry_ind) {
00185             log_inds[thr] = -1;
00186             pending_logs--;
00187         }
00188     }
00189 }
00190 
00191 #endif