oik-bwtrace action and filter trace file – bwaction.loh – Deprecated

No longer relevant. This functionality has been replaced by Count action hooks and filters.

The oik-bwtrace action and filter output file lists the actions and filters invoked on your WordPress server. We use the name bwaction.loh. The format of each record is:

• timestamp – with microseconds
• action start or end indicator
• trace record count
• current filter
• context

The action start or end indicator values are:

• <S = Action start
• E> = Action end
• <I = Immediate action start
• I> = Immediate action end

Here is a sample showing the start of “init” processing.

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_context

In 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 Post

Nearly 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 init

Clearly 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

So that meant there were 800 Immediate action trace records (produced by calls to do_action(), apply_filters(), do_action_ref_array() or apply_filters_ref_array()) for which no hook had been added. Those called more than once were:

Leaving 56 other actions/filters called once each.