[asterisk-dev] Wanted: Missing CPU Cycles... Reward!
Steve Murphy
murf at digium.com
Wed Oct 31 10:06:04 CDT 2007
In my effort to resurrect my long-ignored work on keeping large
dialplans from slowing down the PBX, I unearthed the fact, that somehow,
somewhere, around 20% of the performance of the PBX engine was
"missing"!!!
Where this performance went, I have no idea. But we all need to think on
how we might get them back. I've come up with almost half of them
(percentage points of performance, that is) in one optimization, perhaps
others of you can come up with others.
My test is a simple tight loop of 4 priorities, I've written about and
talked about at conferences previously. Before, about a year ago, I was
seeing 90,000 PIPS from my test system. Yesterday, I measured trunk at
76,000 PIPS. With my optimization, I see 83,000 PIPS.
I've used gprof on my fast-ast2 branch of asterisk, and these are the
contending routines for optimizations:
% cumulative self self total
time seconds seconds calls s/call s/call name
23.83 5.47 5.47 4000005 0.00 0.00
pbx_substitute_variables
11.69 8.15 2.68 2000075 0.00 0.00
pbx_substitute_variables_helper_full
7.89 9.96 1.81 31000437 0.00 0.00 ast_copy_string
6.93 11.55 1.59 8000024 0.00 0.00 ast_yylex
6.76 13.10 1.55 2000004 0.00 0.00 ast_yyparse
6.45 14.58 1.48 3000009 0.00 0.00
pbx_retrieve_variable
5.02 15.73 1.15 4000068 0.00 0.00
ast_hashtab_hash_string
3.66 16.57 0.84 4000023 0.00 0.00 update_scoreboard
2.51 17.14 0.58 8000056 0.00 0.00 ast_hashtab_lookup
1.74 17.54 0.40 1999999 0.00 0.00 ast_parseable_goto
1.29 17.84 0.30 4000014 0.00 0.00
pbx_extension_helper
1.26 18.13 0.29 2000004 0.00 0.00 ast_yy_scan_bytes
1.24 18.41 0.29 6000018 0.00 0.00
parse_variable_name
1.22 18.69 0.28 1000003 0.00 0.00 pbx_builtin_setvar
1.05 18.93 0.24 1000000 0.00 0.00 pbx_builtin_gotoif
1.00 19.16 0.23 1000003 0.00 0.00
pbx_builtin_setvar_helper
0.96 19.38 0.22 3000009 0.00 0.00 substring
0.92 19.59 0.21 1 0.21 22.66 _ast_pbx_run
0.87 19.79 0.20 2000002 0.00 0.00 set_one_cid
0.87 19.99 0.20 4000014 0.00 0.00 pbx_find_extension
0.79 20.17 0.18 2000004 0.00 0.00
ast_yyensure_buffer_stack
0.74 20.34 0.17 4000005 0.00 0.00 pbx_exec
0.70 20.50 0.16 4000008 0.00 0.00 yy_get_next_buffer
0.70 20.66 0.16 2000004 0.00 0.00 ast_yy_scan_string
0.65 20.81 0.15 4000005 0.00 0.00 ast_cdr_setapp
0.59 20.95 0.14 2000004 0.00 0.00 ast_expr
0.57 21.08 0.13 999999 0.00 0.00 op_plus
0.48 21.19 0.11 2000004 0.00 0.00
yy_get_previous_state
0.46 21.29 0.11 10000020 0.00 0.00 ast_yyfree
0.44 21.39 0.10 1000004 0.00 0.00 ast_var_assign
0.39 21.48 0.09 2000004 0.00 0.00 ast_yy_scan_buffer
0.37 21.57 0.09 2000004 0.00 0.00 ast_yylex_destroy
0.35 21.65 0.08 4000042 0.00 0.00
hashtab_compare_contexts
0.31 21.72 0.07 4000012 0.00 0.00 free_value
0.26 21.78 0.06 2000004 0.00 0.00 ast_yylex_init
0.26 21.84 0.06 1999999 0.00 0.00 ast_explicit_goto
0.26 21.90 0.06 1000000 0.00 0.00 op_lt
0.26 21.96 0.06 9632 0.00 0.00 ast_strip
0.24 22.01 0.06 4000008 0.00 0.00
ast_yy_load_buffer_state
0.22 22.06 0.05 8000959 0.00 0.00 ast_check_hangup
0.22 22.11 0.05 1999999 0.00 0.00 pbx_builtin_goto
0.17 22.15 0.04 5000017 0.00 0.00
_init_manager_event_buf
The list above is just the top contenders. Since the loop is executed a
million times,
all the functions called a million or more times were involved in the
"core" of
the PBX (only SETs/no-ops/gotoIf apps used, along with ${} and $[]
expressions.)
Most immediately apparent is that any optimizations to the
substitute_variables
functions could yield HUGE speedups in the code. (And, conversely, any
additions
will immediately slow down asterisk). I plan to overhaul the entire
parsing/evaluation
mechanics for AEL3, which hopefully speed up this stuff, but in the
meantime,
any speedups anywhere might yield some good results for us all.
Note: here's the extensions.conf version of the dialplan I used. Zap
lines are set up
so when an extension is picked up, you are in the "extension" context.
Dial "81" to start
the test.
[dialextens]
exten => _10X,1,Dial(Zap/${EXTEN:2}|30|tw)
exten => _1ZX,1,Dial(Zap/${EXTEN:1}|30|tw)
[dialthrus]
exten => _3XX,1,Dial(Zap/${EXTEN:1}|30|tw)
[t1incoming]
include => dialextens
include => parkedcalls
exten => s,1,Answer()
exten => s,2,Background(welcome-to-test-machine)
[incoming]
include => dialextens
include => parkedcalls
exten => s,1,Answer()
exten => s,2,Background(welcome-to-test-machine)
[extension]
include => dialextens
include => dialthrus
exten => 5,1,Record(recording:gsm)
exten => 5,2,Background(recording)
exten => 81,1,Set(iterations=$[1000000])
exten => 81,2,Set(time1=${EPOCH})
exten => 81,3,Set(i=$[1])
exten => 81,4,GotoIf($[${i}<${iterations}]?5:8)
exten => 81,5,NoOp(Hello)
exten => 81,6,Set(i=$[${i}+1])
exten => 81,7,Goto(4)
exten => 81,8,NoOp(Finish for-extension-1)
exten => 81,9,Set(time2=${EPOCH})
exten => 81,10,Verbose(The time diff is $[${time2} - ${time1} ] seconds)
exten => 81,11,Verbose(Which means that the priorities/sec = $[4*
${iterations} / (${time2} - ${time1}) ])
exten => 81,12,SayNumber($[4 * ${iterations} / (${time2} - ${time1}) ])
exten => 82,1,NoOp(Never here)
exten => 82,2,Verbose(Not here either!)
exten => 83,1,Read(x|beep|1||1|0.3)
exten => 83,2,Read(x|beep|1||1|0.3)
exten => 83,3,Read(x|beep|1||1|0.3)
murf
--
Steve Murphy
Software Developer
Digium
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-dev/attachments/20071031/aa7ff822/attachment-0001.htm
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/x-pkcs7-signature
Size: 3227 bytes
Desc: not available
Url : http://lists.digium.com/pipermail/asterisk-dev/attachments/20071031/aa7ff822/attachment-0001.bin
More information about the asterisk-dev
mailing list