Web developers wiki ASP.NET Sitecore Sharepoint Kentico by Evident Interactive

Sitecore event tracing

Modified: 2012/11/23 16:27 by vanthoog - Categorized as: Sitecore
One of the great features of Sitecore is events. If you want to add custom logic to a standard operation you often do not need to change Sitecore logic; you can just add custom logic to an event.

When you start working with events it is at first difficult to understand which events are available for a certain operation and in which sequence they are invoked. Fortunately it is possible to enable tracing of events by changing the value of the attribute timingLevel in the key events in the web.config. Just set the attribute timingLevel to the value "high" to get maximum tracing information:

    <events timingLevel="high">

Now when you perform a certain operation the event trace will be written to the Sitecore log-file. For example, if you create a content item (in the Sitecore content editor), the following information will be written to the Sitecore log-file:

11052 16:10:46 INFO  Event started: item:creating
11052 16:10:46 INFO  Event ended: item:creating. Elapsed: 0,00326553004450917
11052 16:10:47 INFO  Event started: item:created
11052 16:10:47 INFO  Executed: Sitecore.Caching.RuleCache.OnItemCreated(). Elapsed: 2,6455458403445
11052 16:10:47 INFO  Event ended: item:created. Elapsed: 2,72998311720967
11052 16:10:47 INFO  Event started: item:versionAdding
11052 16:10:47 INFO  Event ended: item:versionAdding. Elapsed: 0,0116626073018185
11052 16:10:47 INFO  Event started: item:saving
11052 16:10:47 INFO  Executed: Sitecore.Tasks.ItemEventHandler.OnItemSaving(). Elapsed: 8,44092866076414
11052 16:10:47 INFO  Event ended: item:saving. Elapsed: 8,52769845908967
11052 16:10:47 INFO  Event started: item:saved
11052 16:10:47 INFO  Executed: Sitecore.Links.ItemEventHandler.OnItemSaved(). Elapsed: 90,7831347502313
11052 16:10:47 INFO  Executed: Sitecore.Globalization.ItemEventHandler.OnItemSaved(). Elapsed: 3,60187963909362
11052 16:10:47 INFO  Executed: Sitecore.Rules.ItemEventHandler.OnItemSaved(). Elapsed: 14,5549339126695
11052 16:10:47 INFO  Executed: Sitecore.Analytics.Data.Items.ItemEventHandler.OnItemSaved(). Elapsed: 19,3925834214638
11052 16:10:47 INFO  Executed: Sitecore.Analytics.Automation.Data.Items.ItemEventHandler.OnAutomationStateChanged(). Elapsed: 1,14853356708308
11052 16:10:47 INFO  Executed: Sitecore.Caching.AccessResultCache.Item_Saved(). Elapsed: 1,73912800084717
11052 16:10:47 INFO  Executed: Sitecore.Caching.RuleCache.OnItemSaved(). Elapsed: 0,830377639889476
11052 16:10:47 INFO  Event ended: item:saved. Elapsed: 132,495149521623
11052 16:10:48 INFO  Event started: item:versionAdded
11052 16:10:48 INFO  Event ended: item:versionAdded. Elapsed: 0,00326553004450917
11052 16:10:48 INFO  Event started: item:added
11052 16:10:48 INFO  Executed: Sitecore.Data.Fields.ItemEventHandler.OnItemAdded(). Elapsed: 1,77131679700019
11052 16:10:48 INFO  Event ended: item:added. Elapsed: 10,8863441598094

In this trace you can see that, when creating a content item, the following events are invoked:
- item:creating
- item:created
- item:versionAdding
- item:saving
- item:saved
- item:versionAdded
- item:added

One word of warning: do not enable event tracing in your production environment because if you do, your Sitecore log-file will be flooded with trace messages. Only use this in a development or test environment.

 © Evident Interactive BV