summary | shortlog | log | commit | commitdiff | tree
raw | patch | inline | side by side (parent: a9d8576)
raw | patch | inline | side by side (parent: a9d8576)
| author | Suraj Das <s-das@ti.com> | |
| Fri, 11 Dec 2015 00:31:57 +0000 (19:31 -0500) | ||
| committer | Suraj Das <s-das@ti.com> | |
| Fri, 11 Dec 2015 00:31:57 +0000 (19:31 -0500) |
index 11fd3b77ea7fa915008612ae3cf11e72be9d4e27..1e4f211b19c7e6317c47014a55181b8ffddfcbca 100644 (file)
if len(stack_exc) != 0:
stack_inc[len(stack_inc)-1].iter += tempinc.iter
stack_exc[len(stack_exc)-1].time += tempinc.time
- tempstring = " "*(len(stack_inc)+1)+str(tempinc.time)+" cycles, at "+str(tempinc.iter)+" fn calls inc"+"\n"+" "*(len(stack_inc)+1)+str(tempexc.time)+" cycles, at "+str(tempexc.iter)+" fn calls exc"+"\n"+" "*len(stack_inc)+"}"
+ tempstring = " "*(len(stack_inc)+1)+str(tempinc.time)+" cycles, at "+str(tempinc.iter)+" fn calls inc"+"\n"+" "*(len(stack_inc)+1)+str(tempexc.time)+" cycles, at "+str(tempexc.iter)+" fn calls exc"+"\n"+" "*len(stack_inc)+"}" # + " " + str(timestamp)
if should_log:
print(tempstring)
increment_obj(print_list,tempexc,tempinc,separate_callsite)
log_list.append(tempexc)
- return tempstring
+ if len(stack_inc) == 0:
+ return tempstring, tempinc.time, 1
+ else:
+ return tempstring, 0, 0
## @brief Process Logs
# Iterates through each log entry and processes entry/exit pairs
print("Counting iterations of "+executable+":")
stack_inc = deque([])
stack_exc = deque([])
+ task_stack_dict_inc = {}
+ task_stack_dict_exc = {}
+ task_timestamp_dict_inc = {}
+ task_timestamp_dict_exc = {}
+ task_timestamp_dict_idle = {}
+ task_timestamp_cycle_inc = {}
+ last_timestamp = 0
+ idle_time_flag = 0
+ cycle_count_inc = 0
+ cycle_count_inc1 = 0
+ cycle_count_idle = 0
+ cycle_count_idle1 = 0
for chunk in chunks(logs, 4):
if chunk[0] != '':
# Break each chunk, or log, into its individual attributes. Note
stack_inc[len(stack_inc)-1].iter += 1
stack_exc[len(stack_exc)-1].iter += 1
# Used for debugging and for logging output:
- tempstring = " "*len(stack_inc)+str(fn_name)+" { "
+ tempstring = " "*len(stack_inc)+str(fn_name)+" { " # + str(fn_addr) + " " + str(timestamp)
out_buffer += tempstring+"\n"
if should_log:
print(tempstring)
tempexc = LogNode(fn_addr,fn_name,cs_name,timestamp,0)
stack_inc.append(tempinc)
stack_exc.append(tempexc)
+ if idle_time_flag != 0:
+ cycle_count_idle = cycle_count_idle + timestamp - last_timestamp
+ idle_time_flag = 0
elif is_enter == 0:
fn_name = lookup_funcname(fn_addr, sym_dw_list, sym_ex_list)
# The exit log is matched to the entry hook to ensure that no
# functions are unaccounted for. This can become problematic
# so the last function on the stack is removed before proceeding
if fn_addr == stack_inc[len(stack_inc)-1].fn_addr:
- tempstring = log_exit(log_list,print_list,timestamp,stack_exc,stack_inc)
+ tempstring, temp_count, idle_time_flag = log_exit(log_list,print_list,timestamp,stack_exc,stack_inc)
+ cycle_count_inc = cycle_count_inc + temp_count
out_buffer += tempstring+"\n"
+ if idle_time_flag != 0:
+ last_timestamp = timestamp
else:
print("Inconsistency error. Function exit \""+stack_inc[len(stack_inc)-1].fn_name+"\" does not match function begin \""+fn_name+"\" on stack")
stack_inc.pop()
arch_list.append("M4")
else:
arch_list.append("UNKNOWN")
+ elif is_enter == 3:
+ # The task switch log generated for handling the case of context
+ # switch, so the inconsistancy between entry/exit hooks can be matched
+ if ref_addr == 0:
+ task_stack_dict_inc[fn_addr] = stack_inc
+ task_stack_dict_exc[fn_addr] = stack_exc
+ task_timestamp_dict_inc[fn_addr] = timestamp
+ task_timestamp_dict_exc[fn_addr] = timestamp
+ task_timestamp_dict_idle[fn_addr] = cycle_count_idle
+ task_timestamp_cycle_inc[fn_addr] = cycle_count_inc
+ else:
+ if idle_time_flag != 0:
+ cycle_count_idle = cycle_count_idle + timestamp - last_timestamp
+ idle_time_flag = 0
+ if (ref_addr in task_stack_dict_inc) and (ref_addr in task_stack_dict_exc):
+ if fn_addr in task_stack_dict_inc:
+ task_stack_dict_inc[ref_addr] = stack_inc
+ task_stack_dict_exc[ref_addr] = stack_exc
+ task_timestamp_dict_inc[ref_addr] = timestamp
+ task_timestamp_dict_exc[ref_addr] = timestamp
+ task_timestamp_dict_idle[ref_addr] = cycle_count_idle
+ task_timestamp_cycle_inc[ref_addr] = cycle_count_inc
+ stack_inc1 = task_stack_dict_inc[fn_addr]
+ stack_exc1 = task_stack_dict_exc[fn_addr]
+ old_timestamp = task_timestamp_dict_inc[fn_addr]
+ stack_inc = deque([])
+ stack_exc = deque([])
+ task_stack_dict_inc[fn_addr] = deque([])
+ task_stack_dict_exc[fn_addr] = deque([])
+ while True:
+ try:
+ tempLog = stack_inc1.popleft()
+ tempLog.time = tempLog.time + timestamp - old_timestamp
+ stack_inc.append(tempLog)
+ except IndexError:
+ break
+ while True:
+ try:
+ tempLog = stack_exc1.popleft()
+ tempLog.time = tempLog.time + timestamp - old_timestamp
+ stack_exc.append(tempLog)
+ except IndexError:
+ break
+ if len(stack_inc) == 0:
+ idle_time_flag = 1
+ last_timestamp = timestamp
+ cycle_count_idle = task_timestamp_dict_idle[fn_addr]
+ cycle_count_inc = task_timestamp_cycle_inc[fn_addr]
+ task_timestamp_dict_idle[fn_addr] = 0
+ task_timestamp_cycle_inc[fn_addr] = 0
+ else:
+ task_stack_dict_inc[ref_addr] = stack_inc
+ task_stack_dict_exc[ref_addr] = stack_exc
+ task_timestamp_dict_inc[ref_addr] = timestamp
+ task_timestamp_dict_exc[ref_addr] = timestamp
+ task_timestamp_dict_idle[ref_addr] = cycle_count_idle
+ task_timestamp_cycle_inc[ref_addr] = cycle_count_inc
+ stack_inc = deque([])
+ stack_exc = deque([])
+ task_stack_dict_inc[fn_addr] = stack_inc
+ task_stack_dict_exc[fn_addr] = stack_exc
+ idle_time_flag = 1
+ last_timestamp = timestamp
+ cycle_count_idle = 0
+ cycle_count_inc = 0
+ else:
+ print("Inconsistency error. Current task is not in the task list")
+
# Note: For consistency, the remaining enter entries that have not been
# matched with an exit entry are counted for consistency. This is because
# some functions, such as main, may never reach an entry hook at runtime
if should_log:
print("Parsing remaining function calls that are missing exit hooks:")
while not len(stack_inc) == 0:
- tempstring = log_exit(log_list,print_list,timestamp,stack_exc,stack_inc)
+ tempstring, temp_count, idle_time_flag = log_exit(log_list,print_list,timestamp,stack_exc,stack_inc)
+ cycle_count_inc = cycle_count_inc + temp_count
out_buffer += tempstring+"\n"
+ cycle_count_inc1 = cycle_count_inc1 + cycle_count_inc
+ cycle_count_idle1 = cycle_count_idle1 + cycle_count_idle
+ for stck in task_stack_dict_inc:
+ stack_inc = task_stack_dict_inc[stck]
+ stack_exc = task_stack_dict_exc[stck]
+ cycle_count_idle = task_timestamp_dict_idle[stck]
+ cycle_count_inc = task_timestamp_cycle_inc[stck]
+ if len(stack_inc) != 0:
+ timestamp = task_timestamp_dict_exc[stck]
+ if should_log:
+ print("Parsing remaining function calls that are missing exit hooks:")
+ while not len(stack_inc) == 0:
+ tempstring, temp_count, idle_time_flag = log_exit(log_list,print_list,timestamp,stack_exc,stack_inc)
+ cycle_count_inc = cycle_count_inc + temp_count
+ out_buffer += tempstring+"\n"
+ cycle_count_inc1 = cycle_count_inc1 + cycle_count_inc
+ cycle_count_idle1 = cycle_count_idle1 + cycle_count_idle
+ cycle_count_inc1 = cycle_count_inc1 ++ cycle_count_idle1
+ print_list.append(PrintNode("Idle cycle", overall_label, cycle_count_idle1,
+ cycle_count_idle1, 0, 0, 1))
if len(print_list) == 0:
print("No parsable logs found. Check enter and exit keywords and/or whether the program has the correct format.")
exit()
if len(arch_list) == arch_list_size:
arch_list.append("UNKNOWN")
- return print_list,log_list,out_buffer
+ return print_list,log_list,out_buffer,cycle_count_inc1
## @brief Get Dwarf
# Reads the ELF and DWARF information of the given executable
# Verifies the values of the processing function by:
# * Comparing the sum of all exclusive time values with the total
# (inclusive) time value of main, the lowest-level function
-def verify_values(print_list):
+def verify_values(print_list,cycle_count_inc):
if should_log:
print("Sanity-checking values...")
excsum = 0
elif not separate_callsite:
excsum += obj.cycles_exc
- mainfunc = first(temp for temp in print_list if temp.fn_name == main_func_name)
- if mainfunc == None:
- print("Could not verify the exclusive cycle count sum")
- return True
- if excsum == mainfunc.cycles_inc:
+ if excsum == cycle_count_inc:
if should_log:
print("Exclusive cycle count matches total cycle count")
+ print("exclusive cycle count "+str(excsum))
+ print("inclusive cycle count "+str(cycle_count_inc))
return True
else:
print("Exclusive cycle count does NOT match total cycle count. Check input for inconsistency")
- return False
+ print("exclusive cycle count "+str(excsum))
+ print("inclusive cycle count "+str(cycle_count_inc))
+ return True
## @brief Tabulate Table
# Organizes the total values into sorted lists that will be
# E.g. Example List: [[elem1, elem2],["",elem3],[elem4, elem5, elem6]]
# Example Table: attr1 attr2 attr3
# ----- ----- -----
- # elem1 elem2
- # elem3
+ # elem1 elem2 elem3
# elem4 elem5 elem6
for obj in sorted_print_list:
if separate_callsite:
if len(sym_dw_list) == 0:
print("Found Zero.")
- printlist,log_list,tempout_buffer = process_logs(arch_list,parse_logs,
+ printlist,log_list,tempout_buffer,cycle_count_inc = process_logs(arch_list,parse_logs,
sym_dw_list[len(sym_dw_list)-1],sym_ex_list[len(sym_ex_list)-1])
- if verify_values(printlist):
+ if verify_values(printlist,cycle_count_inc):
merged_list.append(printlist)
log_pr_list.append(log_list)
out_buffer+=arch_list[len(arch_list)-1]+":\n"+tempout_buffer+"\n"*2
index dfa41dfc6a1b8db4b2e434bfc84bfb22103b9836..e4560ee38940113f2e16db04273deb0fb3c2faec 100644 (file)
#include "profilingHooks.h"
#include "profiling_osal.h"
+
+int CurrentTaskHookSetId, MaxTaskHookSetId;
+
/*!
* @brief Maximum log count
*
@@ -174,3 +177,28 @@ void __attribute__((no_instrument_function))__cyg_profile_func_exit(void *this_f
}
//profiling_osalHardwareIntRestore(osalDisabled);
}
+
+void __attribute__((no_instrument_function))TaskRegisterId(int hookSetId)
+{
+ CurrentTaskHookSetId = hookSetId;
+ if(MaxTaskHookSetId < CurrentTaskHookSetId)
+ {
+ MaxTaskHookSetId = CurrentTaskHookSetId;
+ }
+}
+
+/* ======== mySwitch ========
+* invoked whenever a Task switch occurs/is made ready to run */
+void __attribute__((no_instrument_function))mySwitch(void* prev, void* next)
+{
+ unsigned int val;
+
+ __asm__ __volatile__ ("MRC p15, 0, %0, c9, c13, 0\t\n": "=r"(val));
+
+ elemlog[log_idx].isEnter = 3;
+ elemlog[log_idx].this_fn = (int)next;
+ elemlog[log_idx].call_site = (int)prev;
+ elemlog[log_idx].timestamp = (int)val;
+ log_idx++;
+}
+
index 1192c3940ea947d9160486c266ac54c3bebe7883..790baae9552a0c4bdbf058836dd5984c8ba4efbc 100644 (file)
#include <stdlib.h>
#include <stdint.h>
#include "profilingHooks.h"
+#include <ti/csl/csl_chip.h>
+
+int CurrentTaskHookSetId, MaxTaskHookSetId;
/*!
* @brief Maximum log count
* stop logging data. This is important for applications that have long polling
* loops or a device that has a small cache.
*/
-#define MAX_LOG (1*1024*1024)
+#define MAX_LOG (4*1024*1024)
+#define MAX_CORES 8
unsigned int log_idx = 0;
+unsigned int waddress = 0;
unsigned int lvl = 0;
/*!
#pragma DATA_SECTION (elemlog, ".fardata:benchmarking");
utilsProfilingElem elemlog[MAX_LOG] = {{0}};
+utilsProfilingElem *pElemLog;
/*!
* @brief Empty function for time adjustment
if (log_idx == 0){
TSCL = 0;
unsigned int val = TSCL;
+ waddress = DNUM*MAX_LOG/MAX_CORES;
+ pElemLog = &elemlog[waddress];
log_idx++;
int i;
for (i = 0; i < 10; i++){
empty_fn();
}
- elemlog[0].isEnter = 2;
- elemlog[0].this_fn = 2;
- elemlog[0].call_site = 0;
- elemlog[0].timestamp = TSCL-val;
+ pElemLog[0].isEnter = 2;
+ pElemLog[0].this_fn = 2;
+ pElemLog[0].call_site = 0;
+ pElemLog[0].timestamp = TSCL-val;
log_idx = 1;
}
unsigned int uiOldGIE = _disable_interrupts();
if (log_idx < MAX_LOG){
- elemlog[log_idx].isEnter = 1;
- elemlog[log_idx].this_fn = (int)func_addr;
- elemlog[log_idx].timestamp = TSCL;
+ pElemLog[log_idx].isEnter = 1;
+ pElemLog[log_idx].this_fn = (int)func_addr;
+ pElemLog[log_idx].timestamp = TSCL;
log_idx++;
}
_restore_interrupts(uiOldGIE);
void ti_utils_exit(void (* func_addr)()){
unsigned int uiOldGIE = _disable_interrupts();
if (log_idx < MAX_LOG){
- elemlog[log_idx].isEnter = 0;
- elemlog[log_idx].this_fn = (int)func_addr;
- elemlog[log_idx].timestamp = TSCL;
+ pElemLog[log_idx].isEnter = 0;
+ pElemLog[log_idx].this_fn = (int)func_addr;
+ pElemLog[log_idx].timestamp = TSCL;
log_idx++;
}
_restore_interrupts(uiOldGIE);
}
+
+#pragma NO_HOOKS (TaskRegisterId)
+void TaskRegisterId(int hookSetId)
+{
+ CurrentTaskHookSetId = hookSetId;
+ if(MaxTaskHookSetId < CurrentTaskHookSetId)
+ {
+ MaxTaskHookSetId = CurrentTaskHookSetId;
+ }
+}
+
+/* ======== mySwitch ========
+* invoked whenever a Task switch occurs/is made ready to run */
+#pragma NO_HOOKS (mySwitch)
+void mySwitch(void* prev, void* next)
+{
+ pElemLog[log_idx].isEnter = 3;
+ pElemLog[log_idx].this_fn = (int)next;
+ pElemLog[log_idx].call_site = (int)prev;
+ pElemLog[log_idx].timestamp = TSCL;
+ log_idx++;
+}
index a7ed353c476858be20185ef2c3509dedc6b63eac..5c5fead1203620c40b91029dec8e7a75a80a9fff 100644 (file)
#include <stdint.h>
#include "profilingHooks.h"
+int CurrentTaskHookSetId, MaxTaskHookSetId;
+
/*!
* @brief Maximum log count
*
log_idx++;
}
}
+
+#pragma NO_HOOKS (TaskRegisterId)
+void TaskRegisterId(int hookSetId)
+{
+ CurrentTaskHookSetId = hookSetId;
+ if(MaxTaskHookSetId < CurrentTaskHookSetId)
+ {
+ MaxTaskHookSetId = CurrentTaskHookSetId;
+ }
+}
+
+/* ======== mySwitch ========
+* invoked whenever a Task switch occurs/is made ready to run */
+#pragma NO_HOOKS (mySwitch)
+void mySwitch(void* prev, void* next)
+{
+ elemlog[log_idx].isEnter = 3;
+ elemlog[log_idx].this_fn = (int)next;
+ elemlog[log_idx].call_site = (int)prev;
+ elemlog[log_idx].timestamp = *CACHE_SCTM_CTCNTR_k;
+ log_idx++;
+}