CMS Diagnostics / Reporting
This feature is available since Hippo CMS 10.2.0
Since Hippo CMS 10.2, Hippo CMS has built-in (extensible) support for application diagnostics / reporting. The default out of the box diagnostics prints how long in milliseconds different parts of the CMS request cycle took to execute. It can be switched on and off in development, test, acceptance or production environment, and also can be configured to only be invoked for requests from specific client IP addresses in order to avoid too much logging in a production environment when diagnostics are switched on. The diagnostics in Hippo CMS during a request are held by Task objects, where a Task is a composite structure that can have child Tasks and a parent Task. The child tasks (subtasks) of a task are logged hierarchically indented below the parent task, by default. Thus for example, you will see output like this:
- cms (247ms): {request=}
|- login (30ms): {}
|- PluginPage.init (50ms): {}
| |- PluginContext.connect (0ms): {}
| |- PluginContext.newCluster (0ms): {}
| `- PluginContext.start (35ms): {pluginClass=org.hippoecm.frontend.plugins.login.SimpleLoginPlugin, pluginConfig=home.cluster.login.plugin.loginPage}
| `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.login.SimpleLoginPlugin}
|- PluginPage.onInitialize (0ms): {}
|- PluginPage.processEvents (0ms): {}
| `- PluginPage.onDetach (0ms): {}
|- PluginPage.render (0ms): {}
| `- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.login.SimpleLoginPlugin, pluginConfig=home.cluster.login.plugin.loginPage}
|- PluginPage.onBeforeRender (3ms): {}
| `- AbstractRenderService.onBeforeRender (2ms): {pluginClass=org.hippoecm.frontend.plugins.login.SimpleLoginPlugin, pluginConfig=home.cluster.login.plugin.loginPage}
|- PluginPage.renderHead (0ms): {}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.login.SimpleLoginPlugin, pluginConfig=home.cluster.login.plugin.loginPage}
`- PluginPage.onAfterRender (0ms): {}
Note that all the times accumulated of direct child tasks of a Task cannot exceed the time spent on the Task. Thus above, the sum of time spent in subtask login, PluginPage* and AbstractRenderService cannot exceed the time spent in the parent task, cms.
Out of the box, the Hippo CMS supports diagnostics for the following tasks.
- org.hippoecm.frontend.Main (through "DiagnosticsRequestCycleListener", a Wicket RequestCycleListener implementation) : Normally the same as the total time spend for a CMS request
- org.hippoecm.repository.impl.RepositoryDecorator : Time taken for login
- org.hippoecm.repository.impl.QueryDecorator : Time taken for a query execution
- org.hippoecm.frontend.PluginPage : Normally the same as the whole CMS Wicket page rendering
- org.hippoecm.frontend.plugin.impl.PluginContext : Lifecycle management of each CMS frontend plugin component and invocation on each.
- org.hippoecm.frontend.service.render.AbtractRenderService : Time taken for rendering a CMS frontend plugin component
- org.hippoecm.frontend.service.restproxy.RestProxyServicePlugin : Time taken for an internal server-side REST Proxy Service invocation.
- ...
The default DiagnosticsRequestCycleListener logs its reporting info to the normal hippo-cms.log file. An example of the Gogreen homepage diagnostics is added at the end of this page. In there, you can see the hierarchical output of how long different parts of the request took. For example, the query task which executes a JCR query is logged in the diagnostics logs.
Switching on/off Diagnostics
By default, CMS diagnostics in CMS application is switched off. Switching it on is as simple as adding the property (or setting) enabled = true at /hippo:configuration/hippo:modules/diagnostics/hippo:moduleconfig :
+ hippo:configuration
+ hippo:modules
+ diagnostics
+ hippo:moduleconfig
- enabled = true
When the property is not present, diagnostics are turned off. Once switched on, DiagnosticsRequestCycleListener will start logging application diagnostics at INFO level. To see the logs, you need to set the log level of org.hippoecm.frontend.diagnosis.DiagnosticsRequestCycleListener to INFO or lower. By default, the 10.2 archetype however will already have log4j configured with:
<!-- DiagnosticsRequestCycleListener only logs when diagnostics is enabled in the repository at
/hippo:configuration/hippo:modules/diagnosis
hence can be here on level 'info' -->
<logger name="org.hippoecm.frontend.diagnosis.DiagnosticsRequestCycleListener">
<level value="info"/>
</logger>
For projects created with older archetypes, adding the above <logger> to the log4j configuration is enough.
Diagnostics for access by certain CMS users or from certain client IP address(es) only
If you want to diagnose certain pages in a production environment, sometimes it might be undesirable to have diagnostic logging enabled for every visitor.
In that case, you can give a multi-valued property, allowedUsers, that contains username(s) for which diagnostics should be logged.
+ hippo:configuration
+ hippo:modules
+ diagnostics
+ hippo:moduleconfig
- enabled = true
- allowedUsers = { "editor", "author" }
In this case, the diagnostics will be logged only when the logged CMS user is either "editor" or "author".
Also, you can also give a multi-valued property, allowedAddresses, that contains client IP address(es) for which diagnostics should be logged.
+ hippo:configuration
+ hippo:modules
+ diagnostics
+ hippo:moduleconfig
- enabled = true
- allowedAddresses = {10.10.100.139, 10.10.100.140}
In this case, the diagnostics will be logged only when the client IP address is either "10.10.100.139" or "10.10.100.140".
allowedUsers and allowedAddresses can be set together, in which case the client's username and IP address should be contained in each property value, to see diagnostics logging.
Only log diagnostics if some threshold is exceeded
If you only want to log those request that take more than, say, 1 second the process, you can configure a threshold in milliseconds for this. If you set
+ hippo:configuration
+ hippo:modules
+ diagnostics
+ hippo:moduleconfig
- enabled = true
- thresholdMillisec = 1000
then only when the request took more than 1 second, it will be logged.
Only log the Tasks until some depth
To avoid diagnostics logs to grow too fast, you can configure to only log the task hierarchy until some depth. If you have not configured a depth, the entire Task hiearchy will be logged. If you configure depth = 0, only the root task is logged, depth = 1 logs the root task and its direct children, etc. Logging the root task + direct children would for example be achieved as follows:
+ hippo:configuration
+ hippo:modules
+ diagnostics
+ hippo:moduleconfig
- enabled = true
- depth = 1
Only log the Tasks which exceed some threshold
If you only want to log those tasks which take at least a certain amount of time (to avoid many 0 ms tasks to be logged), you can configure unitThresholdMillisec. If configured and bigger than 0, only tasks that take longer than unitThresholdMillisec will be present in the outputted log. For example:
+ hippo:configuration + hippo:modules + diagnostics + hippo:moduleconfig - enabled = true - unitThresholdMillisec = 1
Customizing Diagnostics
Adding own Tasks
You can add your own diagnostics tasks very easily in CMS frontend plugin code. They will be automatically hierarchically nested below the current active Task. Adding a Task is very simple and can best be shown in code as follows:
Assume you have the following code in your CMS frontend plugin of which you expect that it can be expensive:
public void doSomeExpensiveOperation(final Node node) {
traverseAllDescendants(node);
}
traverseAllDescendants sounds expensive. Changing the above to include CMS application diagnostics Task only takes:
public void doSomeExpensiveOperation(final Node node) {
Task tranverseTask = null;
try {
if (HDC.isStarted()) {
traverseTask = HDC.getCurrentTask().startSubtask("Traverse All Nodes");
}
traverseAllNodes(node);
} finally {
if (traverseTask != null) {
traverseTask.stop();
}
}
}
Now, assume that for every iteration in the recursive traverseAllNodes method you'd also like to update some extra information in the "Traverse All Nodes" task. Then you can change traverseAllNodes method like the following:
private void traverseAllNodes(final Node node) {
// some code etc etc
if (HDC.isStarted()) {
AtomicInteger iterCount =
(AtomicInteger) HDC.getCurrentTask().getAttribute("nodeIterationCount");
if (iterCount == null) {
HDC.getCurrentTask().setAttribute("nodeIterationCount",
new AtomicInteger(1));
} else {
iterCount.incrementAndGet();
}
}
for (.....) {
traverseAllNodes(childNode);
}
}
Example output
2015-11-09 13:48:04,604 INFO [http-nio-8080-exec-10] Diagnosis Summary:
- cms (7000ms): {request=}
|- PluginPage.init (4057ms): {}
| |- PluginContext.connect (0ms): {}
| |- PluginContext.newCluster (2ms): {}
| |- PluginContext.start (2202ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader, pluginConfig=home.cluster.cms-static.plugin.servicesLoader}
| | `- PluginContext.connect (2200ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader}
| | |- PluginContext.newCluster (1ms): {}
| | |- PluginContext.start (4ms): {pluginClass=org.hippoecm.frontend.service.preferences.PreferencesStorePlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.preferencesStoreService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.service.preferences.PreferencesStorePlugin}
| | |- PluginContext.start (2ms): {pluginClass=org.hippoecm.frontend.service.settings.SettingsStorePlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.settingsService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.service.settings.SettingsStorePlugin}
| | |- PluginContext.start (2ms): {pluginClass=org.hippoecm.frontend.service.popup.AjaxPopupService, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.ajaxPopupService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.service.popup.AjaxPopupService}
| | |- PluginContext.start (150ms): {pluginClass=org.hippoecm.frontend.service.restproxy.RestProxyServicePlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.hstRestProxyService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.service.restproxy.RestProxyServicePlugin}
| | |- PluginContext.start (14ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.password.validation.PasswordValidationServiceImpl, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.passwordValidationService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.password.validation.PasswordValidationServiceImpl}
| | |- PluginContext.start (4ms): {pluginClass=org.hippoecm.frontend.translation.LocaleProviderPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.localeProviderService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.translation.LocaleProviderPlugin}
| | |- PluginContext.start (10ms): {pluginClass=org.hippoecm.frontend.editor.layout.LayoutProviderPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.layoutProvider}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.editor.layout.LayoutProviderPlugin}
| | |- PluginContext.start (2ms): {pluginClass=org.hippoecm.frontend.editor.impl.DefaultEditorFactoryPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.defaultEditorFactory}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.editor.impl.DefaultEditorFactoryPlugin}
| | |- PluginContext.start (2ms): {pluginClass=org.hippoecm.frontend.plugins.reviewedactions.HippostdEditorFactoryPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.hippostdEditorFactory}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.reviewedactions.HippostdEditorFactoryPlugin}
| | |- PluginContext.start (20ms): {pluginClass=org.hippoecm.frontend.plugins.richtext.htmlcleaner.HtmlCleanerPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.defaultHtmlCleanerService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.richtext.htmlcleaner.HtmlCleanerPlugin}
| | |- PluginContext.start (38ms): {pluginClass=org.hippoecm.frontend.plugins.richtext.htmlcleaner.HtmlCleanerPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.filteringHtmlCleanerService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.richtext.htmlcleaner.HtmlCleanerPlugin}
| | |- PluginContext.start (4ms): {pluginClass=org.hippoecm.frontend.plugins.standards.diff.HTMLDiffPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.htmlDiffService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.standards.diff.HTMLDiffPlugin}
| | |- PluginContext.start (9ms): {pluginClass=org.hippoecm.frontend.plugins.gallery.processor.ScalingGalleryProcessorPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.galleryProcessorService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.gallery.processor.ScalingGalleryProcessorPlugin}
| | |- PluginContext.start (3ms): {pluginClass=org.hippoecm.frontend.plugins.gallery.NullGalleryProcessorPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.assetProcessorService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.gallery.NullGalleryProcessorPlugin}
| | |- PluginContext.start (71ms): {pluginClass=org.hippoecm.frontend.plugins.yui.upload.validation.ImageUploadValidationPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.imageValidationService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.yui.upload.validation.ImageUploadValidationPlugin}
| | |- PluginContext.start (1ms): {pluginClass=org.hippoecm.frontend.plugins.yui.upload.validation.AssetUploadValidationPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.assetValidationService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.yui.upload.validation.AssetUploadValidationPlugin}
| | |- PluginContext.start (3ms): {pluginClass=org.hippoecm.frontend.translation.TreeNodeIconPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.treeNodeIconService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.translation.TreeNodeIconPlugin}
| | |- PluginContext.start (7ms): {pluginClass=org.onehippo.cms7.channelmanager.plugins.social.PopupSocialMediaService, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.popupSocialMediaService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.cms7.channelmanager.plugins.social.PopupSocialMediaService}
| | |- PluginContext.start (1777ms): {pluginClass=org.onehippo.cms7.channelmanager.service.ChannelDocumentUrlService, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.channelDocumentUrlService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.cms7.channelmanager.service.ChannelDocumentUrlService}
| | |- PluginContext.start (6ms): {pluginClass=org.hippoecm.frontend.i18n.ConfigTraversingPlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.hstEditorConfigTranslator}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.i18n.ConfigTraversingPlugin}
| | |- PluginContext.start (0ms): {pluginClass=org.hippoecm.frontend.service.restproxy.RestProxyServicePlugin, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.hstIntranetRestProxyService}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.service.restproxy.RestProxyServicePlugin}
| | `- PluginContext.start (32ms): {pluginClass=org.onehippo.cms7.channelmanager.templatecomposer.deviceskins.ClassPathDeviceService, pluginConfig=home.cluster.cms-static.plugin.servicesLoader.cluster.cms-services.plugin.defaultDeviceService}
| | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.cms7.channelmanager.templatecomposer.deviceskins.ClassPathDeviceService}
| |- PluginContext.start (4ms): {pluginClass=org.hippoecm.frontend.i18n.ConfigTraversingPlugin, pluginConfig=home.cluster.cms-static.plugin.configTranslator}
| | `- PluginContext.connect (1ms): {pluginClass=org.hippoecm.frontend.i18n.ConfigTraversingPlugin}
| |- PluginContext.start (1ms): {pluginClass=org.hippoecm.frontend.i18n.SearchingTranslatorPlugin, pluginConfig=home.cluster.cms-static.plugin.searchingTranslator}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.i18n.SearchingTranslatorPlugin}
| |- PluginContext.start (51ms): {pluginClass=org.hippoecm.frontend.plugins.cms.root.RootPlugin, pluginConfig=home.cluster.cms-static.plugin.root}
| | |- query (4ms): {statement=SELECT * FROM hipposys:user WHERE fn:name()='admin'}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.root.RootPlugin}
| |- PluginContext.start (13ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.DashboardPerspective, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective}
| | `- PluginContext.connect (3ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.DashboardPerspective}
| |- PluginContext.start (1587ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader, pluginConfig=home.cluster.cms-static.plugin.channelManagerLoader}
| | `- PluginContext.connect (1587ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader}
| | |- PluginContext.newCluster (1ms): {}
| | |- PluginContext.start (1539ms): {pluginClass=org.onehippo.cms7.channelmanager.ChannelManagerPerspective, pluginConfig=home.cluster.cms-static.plugin.channelManagerLoader.cluster.hippo-channel-manager.plugin.channel-manager-perspective}
| | | |- RestProxyServicePlugin (34ms): {class=org.hippoecm.hst.rest.ChannelService, method=canUserModifyChannels}
| | | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.cms7.channelmanager.ChannelManagerPerspective}
| | |- PluginContext.start (2ms): {pluginClass=org.onehippo.cms7.channelmanager.templatecomposer.PlainPropertiesEditor, pluginConfig=home.cluster.cms-static.plugin.channelManagerLoader.cluster.hippo-channel-manager.plugin.templatecomposer-properties-editor}
| | | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.cms7.channelmanager.templatecomposer.PlainPropertiesEditor}
| | |- PluginContext.start (1ms): {pluginClass=org.onehippo.cms7.channelmanager.templatecomposer.PlainVariantAdder, pluginConfig=home.cluster.cms-static.plugin.channelManagerLoader.cluster.hippo-channel-manager.plugin.templatecomposer-variant-adder}
| | | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.cms7.channelmanager.templatecomposer.PlainVariantAdder}
| | `- PluginContext.start (37ms): {pluginClass=org.onehippo.cms7.channelmanager.templatecomposer.deviceskins.DeviceManager, pluginConfig=home.cluster.cms-static.plugin.channelManagerLoader.cluster.hippo-channel-manager.plugin.templatecomposer-device-combo}
| | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.cms7.channelmanager.templatecomposer.deviceskins.DeviceManager}
| |- PluginContext.start (14ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.BrowserPerspective, pluginConfig=home.cluster.cms-static.plugin.browserPerspective}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.BrowserPerspective}
| |- PluginContext.start (25ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.Navigator, pluginConfig=home.cluster.cms-static.plugin.navigator}
| | `- PluginContext.connect (1ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.Navigator}
| |- PluginContext.start (3ms): {pluginClass=org.hippoecm.frontend.plugins.yui.layout.WireframePlugin, pluginConfig=home.cluster.cms-static.plugin.navigatorLayout}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.yui.layout.WireframePlugin}
| |- PluginContext.start (8ms): {pluginClass=org.hippoecm.frontend.plugins.cms.edit.EditorTabsPlugin, pluginConfig=home.cluster.cms-static.plugin.tabbedEditorTabs}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.edit.EditorTabsPlugin}
| |- PluginContext.start (5ms): {pluginClass=org.hippoecm.frontend.plugins.cms.edit.EditorManagerPlugin, pluginConfig=home.cluster.cms-static.plugin.editorManagerPlugin}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.edit.EditorManagerPlugin}
| |- PluginContext.start (11ms): {pluginClass=org.hippoecm.frontend.plugins.cms.edit.AutoEditPlugin, pluginConfig=home.cluster.cms-static.plugin.autoEditPlugin}
| | `- PluginContext.connect (10ms): {pluginClass=org.hippoecm.frontend.plugins.cms.edit.AutoEditPlugin}
| | `- query (8ms): {statement=select * from hippostd:publishable where hippostd:state='draft' and hippostd:holder='admin'}
| |- PluginContext.start (5ms): {pluginClass=org.hippoecm.frontend.plugins.cms.root.ControllerPlugin, pluginConfig=home.cluster.cms-static.plugin.controllerPlugin}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.root.ControllerPlugin}
| |- PluginContext.start (29ms): {pluginClass=org.onehippo.cms7.reports.ReportsPerspective, pluginConfig=home.cluster.cms-static.plugin.reportsPerspective}
| | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.cms7.reports.ReportsPerspective}
| |- PluginContext.start (7ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.AdminPerspective, pluginConfig=home.cluster.cms-static.plugin.adminLoader}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.AdminPerspective}
| |- PluginContext.start (29ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader, pluginConfig=home.cluster.cms-static.plugin.headerbarLoader}
| | `- PluginContext.connect (29ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader}
| | |- PluginContext.newCluster (1ms): {}
| | |- PluginContext.start (24ms): {pluginClass=org.onehippo.cms7.autoexport.plugin.CmsAutoExportPlugin, pluginConfig=home.cluster.cms-static.plugin.headerbarLoader.cluster.cms-header-bar.plugin.autoexport}
| | | `- PluginContext.connect (1ms): {pluginClass=org.onehippo.cms7.autoexport.plugin.CmsAutoExportPlugin}
| | `- PluginContext.start (2ms): {pluginClass=org.onehippo.hst.demo.qa.UsageStatisticsLoggerPlugin, pluginConfig=home.cluster.cms-static.plugin.headerbarLoader.cluster.cms-header-bar.plugin.usage-statistics-logger}
| | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.hst.demo.qa.UsageStatisticsLoggerPlugin}
| |- PluginContext.start (23ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader, pluginConfig=home.cluster.cms-static.plugin.validatorLoader}
| | `- PluginContext.connect (23ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader}
| | |- PluginContext.newCluster (0ms): {}
| | |- PluginContext.start (1ms): {pluginClass=org.hippoecm.frontend.editor.validator.ValidatorService, pluginConfig=home.cluster.cms-static.plugin.validatorLoader.cluster.cms-validators.plugin.registry}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.editor.validator.ValidatorService}
| | |- PluginContext.start (2ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.NonEmptyCmsValidator, pluginConfig=home.cluster.cms-static.plugin.validatorLoader.cluster.cms-validators.plugin.non-empty}
| | | `- PluginContext.connect (1ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.NonEmptyCmsValidator}
| | |- PluginContext.start (2ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.HtmlCmsValidator, pluginConfig=home.cluster.cms-static.plugin.validatorLoader.cluster.cms-validators.plugin.html}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.HtmlCmsValidator}
| | |- PluginContext.start (2ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.EscapedCmsValidator, pluginConfig=home.cluster.cms-static.plugin.validatorLoader.cluster.cms-validators.plugin.escaped}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.EscapedCmsValidator}
| | |- PluginContext.start (2ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.RegExCmsValidator, pluginConfig=home.cluster.cms-static.plugin.validatorLoader.cluster.cms-validators.plugin.email}
| | | `- PluginContext.connect (1ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.RegExCmsValidator}
| | |- PluginContext.start (0ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.NodeReferenceValidator, pluginConfig=home.cluster.cms-static.plugin.validatorLoader.cluster.cms-validators.plugin.references}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.NodeReferenceValidator}
| | |- PluginContext.start (2ms): {pluginClass=org.hippoecm.frontend.i18n.ConfigTraversingPlugin, pluginConfig=home.cluster.cms-static.plugin.validatorLoader.cluster.cms-validators.plugin.validationTranslator}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.i18n.ConfigTraversingPlugin}
| | |- PluginContext.start (1ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.ResourceRequiredValidator, pluginConfig=home.cluster.cms-static.plugin.validatorLoader.cluster.cms-validators.plugin.resource-required}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.editor.validator.plugins.ResourceRequiredValidator}
| | `- PluginContext.start (2ms): {pluginClass=org.onehippo.addon.frontend.gallerypicker.ImageReferenceValidator, pluginConfig=home.cluster.cms-static.plugin.validatorLoader.cluster.cms-validators.plugin.image-references}
| | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.addon.frontend.gallerypicker.ImageReferenceValidator}
| `- PluginContext.start (8ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader, pluginConfig=home.cluster.cms-static.plugin.relatedDocsProvidersClusterLoader}
| `- PluginContext.connect (8ms): {pluginClass=org.hippoecm.frontend.plugin.loader.PluginClusterLoader}
| |- PluginContext.newCluster (1ms): {}
| |- PluginContext.start (3ms): {pluginClass=org.onehippo.forge.relateddocs.providers.SimilaritySearchRelatedDocsProvider, pluginConfig=home.cluster.cms-static.plugin.relatedDocsProvidersClusterLoader.cluster.cms-relateddocsproviders.plugin.SimilaritySearchRelatedDocs}
| | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.forge.relateddocs.providers.SimilaritySearchRelatedDocsProvider}
| |- PluginContext.start (1ms): {pluginClass=org.onehippo.forge.relateddocs.providers.ReferringRelatedDocsProvider, pluginConfig=home.cluster.cms-static.plugin.relatedDocsProvidersClusterLoader.cluster.cms-relateddocsproviders.plugin.ReferringRelatedDocs}
| | `- PluginContext.connect (0ms): {pluginClass=org.onehippo.forge.relateddocs.providers.ReferringRelatedDocsProvider}
| `- PluginContext.start (1ms): {pluginClass=org.onehippo.forge.relateddocs.RelatedDocSuggestor, pluginConfig=home.cluster.cms-static.plugin.relatedDocsProvidersClusterLoader.cluster.cms-relateddocsproviders.plugin.suggestor}
| `- PluginContext.connect (0ms): {pluginClass=org.onehippo.forge.relateddocs.RelatedDocSuggestor}
|- PluginPage.onInitialize (0ms): {}
|- PluginPage.processEvents (3ms): {}
| `- PluginPage.onDetach (1ms): {}
|- PluginPage.render (88ms): {}
| |- AbstractRenderService.render (0ms): {pluginClass=org.onehippo.cms7.autoexport.plugin.CmsAutoExportPlugin, pluginConfig=home.cluster.cms-static.plugin.headerbarLoader.cluster.cms-header-bar.plugin.autoexport}
| |- AbstractRenderService.render (0ms): {pluginClass=org.onehippo.hst.demo.qa.UsageStatisticsLoggerPlugin, pluginConfig=home.cluster.cms-static.plugin.headerbarLoader.cluster.cms-header-bar.plugin.usage-statistics-logger}
| |- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.root.RootPlugin, pluginConfig=home.cluster.cms-static.plugin.root}
| | `- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.standards.tabs.TabsContainerService, pluginConfig=home.cluster.cms-static.plugin.tabbedEditorTabs-tabs-container}
| |- PluginContext.newCluster (1ms): {}
| |- PluginContext.start (9ms): {pluginClass=org.hippoecm.frontend.plugins.yui.layout.WireframePlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.dashboardLayout}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.yui.layout.WireframePlugin}
| |- PluginContext.start (0ms): {pluginClass=org.hippoecm.frontend.service.render.ListViewPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsListPlugin}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.service.render.ListViewPlugin}
| |- PluginContext.start (40ms): {pluginClass=org.hippoecm.frontend.plugin.workflow.ShortcutsPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsPlugin}
| | `- PluginContext.connect (39ms): {pluginClass=org.hippoecm.frontend.plugin.workflow.ShortcutsPlugin}
| | |- query (16ms): {statement=/jcr:root/hippo:configuration/hippo:frontend/cms/cms-dashshortcuts/*/@workaround order by @workaround}
| | |- PluginContext.newCluster (0ms): {}
| | |- PluginContext.start (6ms): {pluginClass=org.hippoecm.frontend.plugins.gotolink.GotolinkDocumentsShortcutPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsPlugin.cluster..plugin.gotoShortcut}
| | | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.gotolink.GotolinkDocumentsShortcutPlugin}
| | `- PluginContext.start (10ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.plugins.ChangePasswordShortcutPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsPlugin.cluster..plugin.changePasswordShortcut}
| | |- query (4ms): {statement=SELECT * FROM hipposys:user WHERE fn:name()='admin'}
| | `- PluginContext.connect (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.plugins.ChangePasswordShortcutPlugin}
| |- PluginContext.start (19ms): {pluginClass=org.hippoecm.frontend.plugins.reporting.ReportPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.currentActivityPlugin}
| | `- PluginContext.connect (17ms): {pluginClass=org.hippoecm.frontend.plugins.reporting.ReportPlugin}
| | |- PluginContext.newCluster (0ms): {}
| | `- PluginContext.start (12ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.current.CurrentActivityPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.currentActivityPlugin.cluster..plugin.reporting:plugin}
| | `- PluginContext.connect (6ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.current.CurrentActivityPlugin}
| |- PluginContext.start (10ms): {pluginClass=org.hippoecm.frontend.plugins.reporting.ReportPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.todoPlugin}
| | `- PluginContext.connect (9ms): {pluginClass=org.hippoecm.frontend.plugins.reporting.ReportPlugin}
| | |- PluginContext.newCluster (0ms): {}
| | `- PluginContext.start (8ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.todo.TodoPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.todoPlugin.cluster..plugin.reporting:plugin}
| | `- PluginContext.connect (3ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.todo.TodoPlugin}
| |- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.DashboardPerspective, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective}
| | |- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.service.render.ListViewPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsListPlugin}
| | |- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.gotolink.GotolinkDocumentsShortcutPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsPlugin.cluster..plugin.gotoShortcut}
| | |- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.plugins.ChangePasswordShortcutPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsPlugin.cluster..plugin.changePasswordShortcut}
| | |- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.current.CurrentActivityPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.currentActivityPlugin.cluster..plugin.reporting:plugin}
| | `- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.todo.TodoPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.todoPlugin.cluster..plugin.reporting:plugin}
| |- AbstractRenderService.render (0ms): {pluginClass=org.onehippo.cms7.channelmanager.ChannelManagerPerspective, pluginConfig=home.cluster.cms-static.plugin.channelManagerLoader.cluster.hippo-channel-manager.plugin.channel-manager-perspective}
| |- AbstractRenderService.render (1ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.BrowserPerspective, pluginConfig=home.cluster.cms-static.plugin.browserPerspective}
| | |- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.edit.EditorTabsPlugin, pluginConfig=home.cluster.cms-static.plugin.tabbedEditorTabs}
| | `- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.Navigator, pluginConfig=home.cluster.cms-static.plugin.navigator}
| |- AbstractRenderService.render (0ms): {pluginClass=org.onehippo.cms7.reports.ReportsPerspective, pluginConfig=home.cluster.cms-static.plugin.reportsPerspective}
| `- AbstractRenderService.render (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.AdminPerspective, pluginConfig=home.cluster.cms-static.plugin.adminLoader}
|- PluginPage.onBeforeRender (639ms): {}
| `- AbstractRenderService.onBeforeRender (639ms): {pluginClass=org.hippoecm.frontend.plugins.cms.root.RootPlugin, pluginConfig=home.cluster.cms-static.plugin.root}
| |- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.standards.tabs.TabsContainerService, pluginConfig=home.cluster.cms-static.plugin.tabbedEditorTabs-tabs-container}
| |- AbstractRenderService.onBeforeRender (39ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.DashboardPerspective, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective}
| | |- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.hippoecm.frontend.service.render.ListViewPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsListPlugin}
| | | |- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.gotolink.GotolinkDocumentsShortcutPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsPlugin.cluster..plugin.gotoShortcut}
| | | `- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.plugins.ChangePasswordShortcutPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsPlugin.cluster..plugin.changePasswordShortcut}
| | |- AbstractRenderService.onBeforeRender (30ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.current.CurrentActivityPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.currentActivityPlugin.cluster..plugin.reporting:plugin}
| | | `- query (5ms): {statement=SELECT * FROM hippolog:item WHERE (hippolog:application = 'cms' OR hippolog:application='repository') ORDER BY hippolog:timestamp DESC}
| | `- AbstractRenderService.onBeforeRender (9ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.todo.TodoPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.todoPlugin.cluster..plugin.reporting:plugin}
| | `- query (6ms): {statement=SELECT * FROM hippostdpubwf:request WHERE NOT hippostdpubwf:type = 'rejected' OR hippostdpubwf:username='admin'}
| |- AbstractRenderService.onBeforeRender (563ms): {pluginClass=org.onehippo.cms7.channelmanager.ChannelManagerPerspective, pluginConfig=home.cluster.cms-static.plugin.channelManagerLoader.cluster.hippo-channel-manager.plugin.channel-manager-perspective}
| |- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.BrowserPerspective, pluginConfig=home.cluster.cms-static.plugin.browserPerspective}
| | |- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.edit.EditorTabsPlugin, pluginConfig=home.cluster.cms-static.plugin.tabbedEditorTabs}
| | `- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.Navigator, pluginConfig=home.cluster.cms-static.plugin.navigator}
| |- AbstractRenderService.onBeforeRender (3ms): {pluginClass=org.onehippo.cms7.reports.ReportsPerspective, pluginConfig=home.cluster.cms-static.plugin.reportsPerspective}
| |- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.AdminPerspective, pluginConfig=home.cluster.cms-static.plugin.adminLoader}
| |- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.onehippo.cms7.autoexport.plugin.CmsAutoExportPlugin, pluginConfig=home.cluster.cms-static.plugin.headerbarLoader.cluster.cms-header-bar.plugin.autoexport}
| `- AbstractRenderService.onBeforeRender (0ms): {pluginClass=org.onehippo.hst.demo.qa.UsageStatisticsLoggerPlugin, pluginConfig=home.cluster.cms-static.plugin.headerbarLoader.cluster.cms-header-bar.plugin.usage-statistics-logger}
|- PluginPage.renderHead (0ms): {}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.gotolink.GotolinkDocumentsShortcutPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsPlugin.cluster..plugin.gotoShortcut}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.plugins.ChangePasswordShortcutPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsPlugin.cluster..plugin.changePasswordShortcut}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.service.render.ListViewPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.shortcutsListPlugin}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.current.CurrentActivityPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.currentActivityPlugin.cluster..plugin.reporting:plugin}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.todo.TodoPlugin, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective.cluster.cms-dashboard.plugin.todoPlugin.cluster..plugin.reporting:plugin}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.dashboard.DashboardPerspective, pluginConfig=home.cluster.cms-static.plugin.dashboardPerspective}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.onehippo.cms7.channelmanager.ChannelManagerPerspective, pluginConfig=home.cluster.cms-static.plugin.channelManagerLoader.cluster.hippo-channel-manager.plugin.channel-manager-perspective}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.Navigator, pluginConfig=home.cluster.cms-static.plugin.navigator}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.edit.EditorTabsPlugin, pluginConfig=home.cluster.cms-static.plugin.tabbedEditorTabs}
|- AbstractRenderService.onAfterRender (1ms): {pluginClass=org.hippoecm.frontend.plugins.cms.browse.BrowserPerspective, pluginConfig=home.cluster.cms-static.plugin.browserPerspective}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.onehippo.cms7.reports.ReportsPerspective, pluginConfig=home.cluster.cms-static.plugin.reportsPerspective}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.admin.AdminPerspective, pluginConfig=home.cluster.cms-static.plugin.adminLoader}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.standards.tabs.TabsContainerService, pluginConfig=home.cluster.cms-static.plugin.tabbedEditorTabs-tabs-container}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.onehippo.cms7.autoexport.plugin.CmsAutoExportPlugin, pluginConfig=home.cluster.cms-static.plugin.headerbarLoader.cluster.cms-header-bar.plugin.autoexport}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.onehippo.hst.demo.qa.UsageStatisticsLoggerPlugin, pluginConfig=home.cluster.cms-static.plugin.headerbarLoader.cluster.cms-header-bar.plugin.usage-statistics-logger}
|- AbstractRenderService.onAfterRender (0ms): {pluginClass=org.hippoecm.frontend.plugins.cms.root.RootPlugin, pluginConfig=home.cluster.cms-static.plugin.root}
`- PluginPage.onAfterRender (0ms): {}