HST Page Diagnostics and Reporting

Bloomreach Content (HST) provides built-in, extensible support for page diagnostics and reporting. By default, diagnostics record the execution time (in milliseconds) for different phases of the HST request cycle. You can enable or disable diagnostics in any environment, including development, test, acceptance, or production. Diagnostics can also be restricted to requests from specific client IP addresses to limit logging in production.

HST tracks diagnostics during a request using Task objects. Each Task can have child tasks and a parent task, forming a hierarchical structure. The diagnostics output displays this hierarchy, with child tasks indented under their parent. For example:

- Foo (50ms): {extra info about task 'Foo'}
    |-subtask Bar (5ms) :  {extra info about task 'Bar'}
    `-subtask Lux (42ms) :   {extra info about task 'Lux'}
            |- subsubtask subLux1 (30ms) :  {extra info about task 'subLux1'}
            ` subsubtask subLux2  (10ms) :  {extra info about task 'subLux2'}

The total time of all direct child tasks cannot exceed the time spent in their parent task. In the example above, the combined time for subtask Bar and subtask Lux cannot exceed the time recorded for Foo.

Default Diagnostic Tasks

HST provides diagnostics for the following tasks:

  • HstFilter: Total time for the HST request.
  • Host and Mount Matching: Time to match the correct mount.
  • Sitemap Matching: Time to match the sitemap item.
  • Pipeline processing: Total processing time for all valves.
  • HstComponentInvokerProfiler: Time for a single doBeforeRender, doAction, or doBeforeServeResource call.
  • HstQuery: Time to execute a query.
  • Dispatcher: Time to render a JSP or Freemarker template.

The default DiagnosticReportingValve writes diagnostics to the standard site.log file. See the example output at the end of this page for a sample of hierarchical diagnostics, including executed queries for HstQuery tasks.

Enabling and Configuring Diagnostics

Diagnostics are disabled by default. To enable diagnostics, set the hst:diagnosticsenabled property to true at /hst:hst/hst:hosts:

/hst:hst:
  /hst:hosts:
    hst:diagnosticsenabled: true

If the property is absent, diagnostics remain disabled. When enabled, the DiagnosticReportingValve logs diagnostics at the INFO level. To view these logs, configure the log level for org.hippoecm.hst.core.container.DiagnosticReportingValve to INFO or lower. Projects created with the Hippo Maven archetype include a default log4j configuration:

<!-- DiagnosticReportingValve only logs when diagnostics enabled in hst:hosts config in repo hence
     can be here on level 'info' -->
<Logger name="org.hippoecm.hst.core.container.DiagnosticReportingValve" level="info"/>

Restricting Diagnostics to Specific Client IP Addresses

To limit diagnostics logging to certain client IP addresses, set the multi-valued property hst:diagnosticsforips with the desired IP addresses:

/hst:hst:
  /hst:hosts:
    hst:diagnosticsenabled: true
    hst:diagnosticsforips: [10.10.100.139, 10.10.100.140]

Only requests from these IP addresses will generate diagnostics logs.

Logging Only Slow Requests

To log diagnostics only for requests exceeding a specified duration, set the hst:diagnosticsthresholdmillisec property (value in milliseconds):

/hst:hst:
  /hst:hosts:
    hst:diagnosticsenabled: true
    hst:diagnosticsthresholdmillisec: 1000

With this configuration, only requests taking longer than 1 second are logged.

Limiting Task Hierarchy Depth in Logs

To control the depth of the task hierarchy in diagnostics logs, set the hst:diagnosticsdepth property. If not set, the full hierarchy is logged. For example, to log only the root task and its direct children:

/hst:hst:
  /hst:hosts:
    hst:diagnosticsenabled: true
    hst:diagnosticsdepth: 1

A value of 0 logs only the root task, 1 logs the root and its immediate children, and so on.

Logging Only Tasks Above a Time Threshold

To exclude tasks that complete quickly, set the hst:diagnosticsunitthresholdmillisec property. Only tasks exceeding this duration (in milliseconds) will appear in the log:

/hst:hst:
  /hst:hosts:
    hst:diagnosticsenabled: true
    hst:diagnosticsunitthresholdmillisec: 1

Adding Custom Diagnostics Tasks

You can add custom diagnostics tasks to track specific operations. Custom tasks are automatically nested under the current active Task. For example, if you have a potentially expensive operation in an HstComponent:

@Override
public void doBeforeRender(HstRequest request, HstResponse response)
                                           throws HstComponentException {
    HippoBean rootBean = getSiteContentBaseBean(request);
    traverseAllBeans(rootBean);
}

To add a diagnostics task for this operation, wrap the code with a subtask:

@Override
public void doBeforeRender(HstRequest request, HstResponse response)
                                          throws HstComponentException {
    try (Task queryTask = HDC.getCurrentTask().startSubtask("Traverse All Beans")) {
        HippoBean rootBean = getSiteContentBaseBean(request);
        traverseAllBeans(rootBean);
    }
}

To record additional information, such as an iteration count during recursion, update the current task's attributes:

private void traverseAllBeans(HippoBean bean) {
    // ...
    AtomicInteger iterCount = (AtomicInteger) HDC.getCurrentTask().getAttribute("HippoBeanIterationCount");
    if (iterCount == null) {
        HDC.getCurrentTask().setAttribute("HippoBeanIterationCount", new AtomicInteger(1));
    } else {
        iterCount.incrementAndGet();
    }

    for (...) {
        traverseAllBeans(childBean);
    }
}

You can also add custom tasks using AOP-based Spring configuration. For an example, see the SpringComponentManager-trace.xml file in the Bloomreach repository.

Implementing a Custom Diagnostics Valve

By default, diagnostics are logged to site.log by the DiagnosticReportingValve. To change the logging format, expose diagnostics via JMX, write to a database, or implement other custom behavior, override the diagnosticReportingValve bean in your hst-assembly.overrides:

<bean id="diagnosticReportingValve" parent="abstractValve"
      class="org.hippoecm.hst.core.container.DiagnosticReportingValve">
</bean>

Example Diagnostics Output

The following example shows diagnostics output for a request to the Gogreen homepage:

03.12.2012 14:40:46 INFO  [org.hippoecm.hst.core.container.DiagnosticReportingValve.logDiagnosticSummary():52] Diagnostic Summary:
- HstFilter (124ms): {hostName=www.demo.test.onehippo.com, uri=/site/, query=null}
  |- Host and Mount Matching (0ms): {}
  |- Sitemap Matching (0ms): {}
  `- Pipeline processing (124ms): {pipeline=null}
     |- Targeting update valve (4ms): {}
     |- HstComponentInvokerProfiler (4ms): {method=doBeforeRender, window=homepage, component=com.onehippo.gogreen.components.DefaultPageComponent, ref=r46}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=main, component=com.onehippo.gogreen.components.BaseComponent, ref=r46_r1}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=home-boxes-left, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r1}
     |- HstComponentInvokerProfiler (4ms): {method=doBeforeRender, window=latestjobs, component=com.onehippo.gogreen.components.common.LatestItems, ref=r46_r1_r1_r1, HippoBeanIterationCount=1}
     |  `- HstQuery (4ms): {query=//*[(@hippo:paths='a5a24dd3-04a0-4ed1-a59a-ffc960ae69f2') and (@hippo:availability='live') and not(@jcr:primaryType='nt:frozenNode') and ((@jcr:primaryType='hippogogreen:job'))] order by @hippogogreen:closingdate descending}
     |- HstComponentInvokerProfiler (8ms): {method=doBeforeRender, window=latestcomments, component=com.onehippo.gogreen.components.common.LatestItems, ref=r46_r1_r1_r2, HippoBeanIterationCount=1}
     |  `- HstQuery (8ms): {query=//*[(@hippo:paths='a9868436-8f6a-4da0-9b67-7eb6e013c885') and (@hippo:availability='live') and not(@jcr:primaryType='nt:frozenNode') and ((@jcr:primaryType='hippogogreen:comment'))] order by @hippostdpubwf:lastModificationDate descending}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=home-boxes-right, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r2}
     |- HstComponentInvokerProfiler (4ms): {method=doBeforeRender, window=latestevents, component=com.onehippo.gogreen.components.common.LatestItems, ref=r46_r1_r2_r2, HippoBeanIterationCount=1}
     |  `- HstQuery (4ms): {query=//*[(@hippo:paths='392850eb-ba46-472f-a1d5-e69aeccfb65d') and (@hippo:availability='live') and not(@jcr:primaryType='nt:frozenNode') and (@hippogogreen:date >= xs:dateTime('2012-12-03T14:40:46.638+01:00')) and ((@jcr:primaryType='hippogogreen:event'))] order by @hippogogreen:closingdate ascending}
     |- HstComponentInvokerProfiler (8ms): {method=doBeforeRender, window=latestreviews, component=com.onehippo.gogreen.components.common.LatestItems, ref=r46_r1_r2_r3, HippoBeanIterationCount=1}
     |  `- HstQuery (8ms): {query=//*[(@hippo:paths='6896b028-bfaf-48fd-bd35-6fe38cea758b') and (@hippo:availability='live') and not(@jcr:primaryType='nt:frozenNode') and ((@jcr:primaryType='hippogogreen:review'))] order by @hippogogreen:closingdate descending}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=home-boxes-promo, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r3}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=banner, component=com.onehippo.gogreen.components.common.Banner, ref=r46_r1_r3_r1}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=home-banner, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r4}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=bannercarousel, component=com.onehippo.gogreen.components.common.BannerCarousel, ref=r46_r1_r4_r1}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=home-boxes-intro, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r5}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=banner, component=com.onehippo.gogreen.components.common.Banner, ref=r46_r1_r5_r1}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=featuredproducts, component=com.onehippo.gogreen.components.products.FeaturedProducts, ref=r46_r1_r5_r2}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=body, component=org.hippoecm.hst.core.component.GenericHstComponent, ref=r46_r2}
     |- HstComponentInvokerProfiler (4ms): {method=doBeforeRender, window=header, component=com.onehippo.gogreen.components.common.WebsiteLogo, ref=r46_r3}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=topnav, component=org.hippoecm.hst.core.component.GenericHstComponent, ref=r46_r3_r1}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=search, component=org.hippoecm.hst.core.component.GenericHstComponent, ref=r46_r3_r2}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=mainnavigation, component=com.onehippo.gogreen.components.common.SiteMenu, ref=r46_r3_r3}
     |- HstComponentInvokerProfiler (4ms): {method=doBeforeRender, window=langnavigation, component=com.onehippo.gogreen.components.common.LanguageComponent, ref=r46_r3_r4}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=login, component=com.onehippo.gogreen.components.common.Login, ref=r46_r3_r5}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=footer, component=com.onehippo.gogreen.components.FooterComponent, ref=r46_r4}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=service, component=com.onehippo.gogreen.components.common.SiteMenu, ref=r46_r4_r1}
     |- HstComponentInvokerProfiler (0ms): {method=doBeforeRender, window=sections, component=com.onehippo.gogreen.components.common.SiteMenu, ref=r46_r4_r2}
     |- HstComponentInvokerProfiler (4ms): {method=doRender, window=sections, component=com.onehippo.gogreen.components.common.SiteMenu, ref=r46_r4_r2}
     |  `- Dispatcher (4ms): {dispatch=/WEB-INF/jsp/standard/footer/menu.jsp}
     |- HstComponentInvokerProfiler (4ms): {method=doRender, window=service, component=com.onehippo.gogreen.components.common.SiteMenu, ref=r46_r4_r1}
     |  `- Dispatcher (4ms): {dispatch=/WEB-INF/jsp/standard/footer/menu.jsp}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=footer, component=com.onehippo.gogreen.components.FooterComponent, ref=r46_r4}
     |  `- Dispatcher (0ms): {dispatch=/WEB-INF/jsp/standard/footer/footer.jsp}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=login, component=com.onehippo.gogreen.components.common.Login, ref=r46_r3_r5}
     |  `- Dispatcher (0ms): {dispatch=/WEB-INF/jsp/standard/header/login.jsp}
     |- HstComponentInvokerProfiler (8ms): {method=doRender, window=langnavigation, component=com.onehippo.gogreen.components.common.LanguageComponent, ref=r46_r3_r4}
     |  `- Dispatcher (8ms): {dispatch=/WEB-INF/jsp/standard/header/langnavigation.jsp}
     |- HstComponentInvokerProfiler (4ms): {method=doRender, window=mainnavigation, component=com.onehippo.gogreen.components.common.SiteMenu, ref=r46_r3_r3}
     |  `- Dispatcher (4ms): {dispatch=/WEB-INF/jsp/standard/header/mainnavigation.jsp}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=search, component=org.hippoecm.hst.core.component.GenericHstComponent, ref=r46_r3_r2}
     |  `- Dispatcher (0ms): {dispatch=/WEB-INF/jsp/standard/header/search.jsp}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=topnav, component=org.hippoecm.hst.core.component.GenericHstComponent, ref=r46_r3_r1}
     |  `- Dispatcher (0ms): {dispatch=/WEB-INF/jsp/standard/header/topnav.jsp}
     |- HstComponentInvokerProfiler (4ms): {method=doRender, window=header, component=com.onehippo.gogreen.components.common.WebsiteLogo, ref=r46_r3}
     |  `- Dispatcher (4ms): {dispatch=/hst:hst/hst:configurations/common/hst:templates/standard.header.ftl}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=body, component=org.hippoecm.hst.core.component.GenericHstComponent, ref=r46_r2}
     |- HstComponentInvokerProfiler (8ms): {method=doRender, window=featuredproducts, component=com.onehippo.gogreen.components.products.FeaturedProducts, ref=r46_r1_r5_r2}
     |  `- Dispatcher (8ms): {dispatch=/WEB-INF/jsp/products/featured.jsp}
     |- HstComponentInvokerProfiler (4ms): {method=doRender, window=banner, component=com.onehippo.gogreen.components.common.Banner, ref=r46_r1_r5_r1}
     |  `- Dispatcher (4ms): {dispatch=/WEB-INF/jsp/common/banner.jsp}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=home-boxes-intro, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r5}
     |  `- Dispatcher (0ms): {dispatch=/org/hippoecm/hst/pagecomposer/builtin/components/vbox.ftl}
     |- HstComponentInvokerProfiler (8ms): {method=doRender, window=bannercarousel, component=com.onehippo.gogreen.components.common.BannerCarousel, ref=r46_r1_r4_r1}
     |  `- Dispatcher (8ms): {dispatch=/WEB-INF/jsp/common/bannercarousel.jsp}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=home-banner, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r4}
     |  `- Dispatcher (0ms): {dispatch=/org/hippoecm/hst/pagecomposer/builtin/components/vbox.ftl}
     |- HstComponentInvokerProfiler (4ms): {method=doRender, window=banner, component=com.onehippo.gogreen.components.common.Banner, ref=r46_r1_r3_r1}
     |  `- Dispatcher (4ms): {dispatch=/WEB-INF/jsp/common/banner.jsp}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=home-boxes-promo, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r3}
     |  `- Dispatcher (0ms): {dispatch=/org/hippoecm/hst/pagecomposer/builtin/components/vbox.ftl}
     |- HstComponentInvokerProfiler (4ms): {method=doRender, window=latestreviews, component=com.onehippo.gogreen.components.common.LatestItems, ref=r46_r1_r2_r3}
     |  `- Dispatcher (4ms): {dispatch=/WEB-INF/jsp/reviews/latest.jsp}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=latestevents, component=com.onehippo.gogreen.components.common.LatestItems, ref=r46_r1_r2_r2}
     |  `- Dispatcher (0ms): {dispatch=/WEB-INF/jsp/events/latest.jsp}
     |- HstComponentInvokerProfiler (4ms): {method=doRender, window=home-boxes-right, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r2}
     |  `- Dispatcher (4ms): {dispatch=/org/hippoecm/hst/pagecomposer/builtin/components/vbox.ftl}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=latestcomments, component=com.onehippo.gogreen.components.common.LatestItems, ref=r46_r1_r1_r2}
     |  `- Dispatcher (0ms): {dispatch=/WEB-INF/jsp/comments/latest.jsp}
     |- HstComponentInvokerProfiler (4ms): {method=doRender, window=latestjobs, component=com.onehippo.gogreen.components.common.LatestItems, ref=r46_r1_r1_r1}
     |  `- Dispatcher (4ms): {dispatch=/WEB-INF/jsp/jobs/latest.jsp}
     |- HstComponentInvokerProfiler (0ms): {method=doRender, window=home-boxes-left, component=org.hippoecm.hst.pagecomposer.builtin.components.StandardContainerComponent, ref=r46_r1_r1}
     |  `- Dispatcher (0ms): {dispatch=/org/hippoecm/hst/pagecomposer/builtin/components/vbox.ftl}
     |- HstComponentInvokerProfiler (12ms): {method=doRender, window=main, component=com.onehippo.gogreen.components.BaseComponent, ref=r46_r1}
     |  `- Dispatcher (12ms): {dispatch=/WEB-INF/jsp/home/main.jsp}
     `- HstComponentInvokerProfiler (4ms): {method=doRender, window=homepage, component=com.onehippo.gogreen.components.DefaultPageComponent, ref=r46}
        `- Dispatcher (4ms): {dispatch=/hst:hst/hst:configurations/common/hst:templates/layout.webpage.ftl}
Share Feedback
Page: /build/request-handling/hst-page-diagnostics
Section: Build
Category *
HST Page Diagnostics / Reporting | Bloomreach Content Documentation