How to Observe Timing of Functions Within a Process? (Doc ID 1403933.1)

Last updated on SEPTEMBER 14, 2016

Applies to:

Oracle Communications Messaging Server - Version 6.0.0 and later
Information in this document applies to any platform.
***Checked for relevance on 30-Jul-2013***

Goal

How can you tell how long any given function within a process or thread is taking?

In looking at pstack of a multi-threaded processes which seems to be performing slowly or is hung, you might see threads with stacks which seem similar.  For example, many threads in a tcp_smtp_server process with stacks like the following might lead to the conclusion that wait_for_available() is a bottleneck for some reason:

fd6154b0 lwp_park (0, 0, 61f5)
fd612e74 cond_wait (499e98, 499e68, ...
fd612eb0 pthread_cond_wait (499e98, 499e68, ...
fbb207a8 CM_MT_cond_wait (499e98, 499e68, ...
fbb16fa0 wait_for_available (499e20, 0, fbb333b8, 26, 499de8, fbb18708) + 6c
fbb17c44 CMAE_ClientPoolGrabSessionContext (499e20, f61eaa00, ...
fbb1af80 bmiEndMessage (3472c28, 3472c28, fbb222ce, 0, bc, fbb333b8) + ec
feaf1708 mmc_wtend (2f44c60, c98860, f61f18dc, f61f14a8, 2, 3) + 15e8
fe9abb80 data (f61f14a8, 2, ffffffff, 1, f61f28e4, 13790) + 1750
fe9bb438 smtpc_enqueue (1, f61f28e4, 27408, 13790, 1, 1) + 1548
00013cbc tcp_smtp_slave (13870, f61f3b10, 1, f61f3e9c, 4, 0) + 21c
0001250c tcp_smtp_slave_pre (d, 0, 4, 0, 0, 0) + 34
feb76648 dispatcher_newtcp (14ad50, 0, 0, 0, 0, 0) + 458
fd615370 _lwp_start (0, 0, 0, 0, 0, 0)

What that stack shows is that a Messaging Server MTA function called a 3rd party library function which eventually resulted in a call to wait_for_available() which ultimately resulted in lwp_park() which means the thread is waiting for some external event.

Seeing many threads in all the tcp_smtp_server processes with stacks like above might lead to the conclusion that something about that 3rd party library is a bottleneck and is causing delays in the tcp_smtp_server processes receiving incoming messages.  But from pstack, you really cannot tell how long any one of those calls is taking.  It could be that they process very quickly and there just so many of them that they appear frequently in the pstack output.  Or it could be that they are taking a very long time and are therefore the cause of the performance problem.

How can you tell how long any given function is taking?

Solution

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms