You can do that with a custom ViewDeclarationLanguage whereby you measure the createView(), buildView(), renderView() and if necessary restoreView() methods.
Here's a kickoff example:
public class VdlLogger extends ViewDeclarationLanguageWrapper {
private static final Logger logger = Logger.getLogger(VdlLoggerFactory.class.getName());
private ViewDeclarationLanguage wrapped;
public VdlLogger(ViewDeclarationLanguage wrapped) {
this.wrapped = wrapped;
}
@Override
public UIViewRoot createView(FacesContext context, String viewId) {
long start = System.nanoTime();
UIViewRoot view = super.createView(context, viewId);
long end = System.nanoTime();
logger.info(String.format("create %s: %.6fms", viewId, (end - start) / 1e6));
return view;
}
@Override
public void buildView(FacesContext context, UIViewRoot view) throws IOException {
long start = System.nanoTime();
super.buildView(context, view);
long end = System.nanoTime();
logger.info(String.format("build %s: %.6fms", view.getViewId(), (end - start) / 1e6));
}
@Override
public void renderView(FacesContext context, UIViewRoot view) throws IOException {
long start = System.nanoTime();
super.renderView(context, view);
long end = System.nanoTime();
logger.info(String.format("render %s: %.6fms", view.getViewId(), (end - start) / 1e6));
}
@Override
public ViewDeclarationLanguage getWrapped() {
return wrapped;
}
}
To get it to run, create the below factory:
public class VdlLoggerFactory extends ViewDeclarationLanguageFactory {
private ViewDeclarationLanguageFactory wrapped;
public VdlLoggerFactory(ViewDeclarationLanguageFactory wrapped) {
this.wrapped = wrapped;
}
@Override
public ViewDeclarationLanguage getViewDeclarationLanguage(String viewId) {
return new VdlLogger(wrapped.getViewDeclarationLanguage(viewId));
}
@Override
public ViewDeclarationLanguageFactory getWrapped() {
return wrapped;
}
}
And register it as below in faces-config.xml:
<factory>
<view-declaration-language-factory>com.example.VdlLoggerFactory</view-declaration-language-factory>
</factory>
The createView() is the step of creating the concrete UIViewRoot instance based on <f:view> and <f:metadata> present in the view files. When using Facelets (XHTML) as view, during this step all associated XHTML files will be parsed by the SAX parser and cached for a time as defined in javax.faces.FACELETS_REFRESH_PERIOD. So it may happen that it's one time relatively slow and the other time blazing fast.
The buildView() is the step of populating the JSF component tree (the getChildren() of UIViewRoot) based on the view (XHTML) composition. During this step, all taghandlers (JSTL and friends) are executed and all EL expressions in those taghandlers and component's id and binding attributes are evaluated (for detail, see also JSTL in JSF2 Facelets... makes sense?). So if backing beans are constructed for first time during view build time and invoking business logic during @PostConstruct, then it may happen that this is time consuming.
The renderView() is the step of generating the HTML output based on JSF component tree and the model, starting with UIViewRoot#encodeAll(). So if backing beans are constructed for first time during view render time and invoking business logic during @PostConstruct, then it may happen that this is time consuming.
If backing beans are incorrectly performing business logic in getter methods instead of in @PostConstruct or any other one-time-occurring life cycle event listener, then it may happen that this consumes yet more time. See also Why JSF calls getters multiple times.
