- timestamp – with microseconds
- action start or end indicator
- trace record count
- current filter
- context
- <S = Action start
- E> = Action end
- <I = Immediate action start
- I> = Immediate action end
2012-12-20 10:02:59 0.71846600 <I 711 cf! do_action init 2012-12-20 10:02:59 0.71975400 <S 712 cf=init 2012-12-20 10:02:59 0.72103000 <I 713 cf=init apply_filters gettext_with_contextIn these examples we have both action and Immediate action tracing enabled. Note: You cannot perform Immediate action tracing without also having selected Action tracing. Here are excerpts of the matching trace records from bwtrace.loh
711 cf! 0 16836880/17396408 do_action(74) init 712 cf=init 0 16837880/17396408 bw_trace_action_start(26) arg1 713 cf=init 0 16838160/17396408 apply_filters(1250) gettext_with_context PostNearly 900 trace records later we find the end of “init” processing
2012-12-20 10:03:01 0.63814200 E> 1611 cf=init 2012-12-20 10:03:01 0.64196800 I> 1612 cf! do_action initClearly there’s a lot of processing in “init”. Further analysis of the action log for this particular part of the transaction reveals the following. Of the 870 action or filter records, only 18 of the calls were actually hooked into by the active plugins. These were:
- init – obviously
- oik_fields_loaded
- oik_loaded
- option_blog_charset
- option_category_base – called 3 times
- option_home
- option_siteurl – called 5 times
- option_tag_base – called 2 times
- widgets_init
- wp_default_scripts
- wp_default_styles
Hook | Invocations |
---|---|
gettext | 482 |
gettext_with_context | 119 |
wp_register_sidebar_widget | 70 |
sanitize_key | 22 |
registered_post_type | 14 |
attribute_escape | 8 |
registered_taxonomy | 5 |
pre_option_siteurl | 5 |
pre_option_cron | 4 |
option_cron | 4 |
site_url | 4 |
pre_option_category_base | 3 |
pre_option_tag_base | 2 |
includes_url | 2 |