[asterisk-dev] asterisk profiling...

[Luigi Rizzo]

i have decided to do a bit of profiling of the locking in asterisk,
and with a little bit of code (maybe 100 lines total)
implemented a simple 'show profile' command that lets you track
the time spent in various sections of code using the TSC timer.
I will post the code once polished.

Below, you see the output generated by putting (automatically)
wrappers around the various mutex_lock functions, slightly modified
so that we first do (and time) a trylock, and if it fails we then do
the blocking operation (not timed to avoid counting time
where the CPU is doing other things).

Note something interesting: i have no IAX devices connected, yet
iax2 does approx 200 mutex_lock per second.
Each mutex lock in my case costs between 1000 and 2000 ticks
(it is a 2 GHz CPU).

more data later...
if you have any ideas on places to profile, let me know.
the mechanism is good for counting time as well as events
or other user-defined values.

	cheers
	luigi

*CLI> show uptime 
System uptime: 2 minutes, 54 seconds 
*CLI> show profile chan
profile values (183, allocated 190)
-------------------
item     scale        events   total_ticks   avg_ticks  event_name
    15: [       0]          0            0            0 mtx_lock_chanvars.c
    36: [       0]         43        47148         1096 mtx_lock_channel.c
    60: [       0]          2         3480         1740 mtx_lock_chan_agent.c
    61: [       0]          0            0            0 mtx_lock_chan_features.c
    64: [       0]      40773     40135552          984 mtx_lock_chan_iax2.c
    65: [       0]          0            0            0 mtx_lock_chan_local.c
    66: [       0]        714      1013180         1419 mtx_lock_chan_mgcp.c
    67: [       0]          0            0            0 mtx_lock_chan_oss.c
    68: [       0]       2729      3406424         1248 mtx_lock_chan_sip.c
    69: [       0]        178       509808         2864 mtx_lock_chan_skinny.c
    70: [       0]        357       513900         1439 mtx_lock_chan_zap.c
    76: [       0]          0            0            0 mtx_lock_app_chanisavail.c
    77: [       0]          0            0            0 mtx_lock_app_chanspy.c
    85: [       0]          0            0            0 mtx_lock_app_dumpchan.c
   167: [       0]          0            0            0 mtx_lock_func_channel.c