查找程序栈耗时

showeslap.sh

#!stap

global elapsed_times
global stack_depths_by_tid

probe begin { 
	printf("%s\n","running ... ")
}
probe end{ 
	printf("%s\n","ending .... ")
}
function print_stack_info( thread_id, probe_name, stack_depth, begin_time, end_time ){
	address = addr()
	if( -1 == end_time){
		printf("elapsed_time:%d call   tid:%d -- depth:d|%-*s|name:%s addr:%d begin_time:%d\n",
			0, thread_id, stack_depth, stack_depth,"", probe_name, address, begin_time )
	}else{
		printf("elapsed_time:%d return tid:%d -- depth:d|%-*s|name:%s addr:%d begin_time:%d end_time:%d\n",
			end_time-begin_time, thread_id, stack_depth, stack_depth,"", probe_name, address, begin_time, end_time )
	}
}

probe process(@1).function("*").call {
	thread_id = tid()
	probe_name =probefunc()
	stack_depth = ++stack_depths_by_tid[thread_id]
	begin_time = gettimeofday_us()
	elapsed_times[thread_id,probe_name,stack_depth ]=begin_time
	print_stack_info( thread_id, probe_name, stack_depth, begin_time, -1)
}

probe process(@1).function("*").return{
	thread_id = tid()
	probe_name =probefunc()
	stack_depth = stack_depths_by_tid[thread_id]
	begin_time = elapsed_times[thread_id,probe_name,stack_depth]
/* TODO: some function only have return record, there isn't call record, why? ie. apsara:StringTo<uint32_t> */
	if( 0 != begin_time ){
		stack_depths_by_tid[thread_id]--
	}
	end_time = gettimeofday_us()
	print_stack_info( thread_id, probe_name, stack_depth, begin_time, end_time )
	delete elapsed_times[thread_id,probe_name,stack_depth]
}