How can I log method expressions of JSF ajax requests

Question

I have figured out how to log when a request is an ajax request and which page it is from, in a filter.

What I would really like to do is log what the ajax request is actually for. Such as the name of the method being called by the ajax (eg "findAddress" in this call:<p:ajax process="contactDetails" update="@form" listener="#{aboutYouController.findAddress}" .... )

How can I do this? My app has many ajax requests and I want to log which are being triggered.

public class TrackingFilter implements Filter {

private static Logger LOG = Logger.getLogger(TrackingFilter.class);

@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws ServletException, IOException {    

    HttpServletRequest req = (HttpServletRequest) request;

    String pageHit = req.getRequestURI().substring(req.getContextPath().length()+1).replace(".xhtml", "");
    if(!pageHit.contains("javax.faces.resource")){ // if is a url we want to log
        if ("partial/ajax".equals(req.getHeader("Faces-Request"))) {
            LOG.trace("ajax on URI: " + req.getRequestURI());
        }

Answer 1

What I would really like to do is log what the ajax request is actually for. Such as the name of the method being called by the ajax (eg "findAddress" in this call:<p:ajax process="contactDetails" update="@form" listener="#{aboutYouController.findAddress}" ....)

This information is only available in the JSF component tree. The JSF component tree is only available after view build time. A view is only built when the request has been served by FacesServlet. Thus, a servlet filter is way too early as it runs before any servlet.

You'd better run the code after the restore view phase of a postback. The JSF component tree is guaranteed to be available during that moment. You can use FacesContext#isPostback() to check if the current request is a postback. You can use PartialViewContext#isAjaxRequest() to check if the current request is an ajax request. You can use the predefined javax.faces.source request parameter to obtain the client ID of the source component of the ajax request. You can use the predefined javax.faces.behavior.event request parameter to obtain the ajax event name (e.g. change, click, action, etc).

Obtaining the associated behavior listeners is in turn a story apart. This is easy on ActionSource2 components (e.g. <h|p:commandButton action="#{...}">) as the MethodExpression is just available by ActionSource2#getActionExpression(). However, this isn't easy on BehaviorBase taghandlers (e.g. <f|p:ajax listener="#{...}">) as this API doesn't have any method like getBehaviorListeners(). There are only methods to add and remove them, but not to obtain a list of them. So some nasty reflection trickery is necessary to access the private field with those listeners whose name is JSF implementation specific. In Mojarra it's listeners and in MyFaces it's _behaviorListeners. Both are fortunately assignable from List and it's the only field of that type, so we could just check for that. Once having hand of the BehaviorListener instance, then you still need to do another reflection trickery to obtain the MethodExpression field of that instance. Yuck.

All in all, here's how the trickery look like in flavor of a PhaseListener listening on afterPhase of RESTORE_VIEW:

public class AjaxActionLoggerPhaseListener implements PhaseListener {

    @Override
    public PhaseId getPhaseId() {
        return PhaseId.RESTORE_VIEW;
    }

    @Override
    public void beforePhase(PhaseEvent event) {
        // NOOP.
    }

    @Override
    public void afterPhase(PhaseEvent event) {
        FacesContext context = event.getFacesContext();

        if (!(context.isPostback() && context.getPartialViewContext().isAjaxRequest())) {
            return; // Not an ajax postback.
        }

        Map<String, String> params = context.getExternalContext().getRequestParameterMap();
        String sourceClientId = params.get("javax.faces.source");
        String behaviorEvent = params.get("javax.faces.behavior.event");

        UIComponent source = context.getViewRoot().findComponent(sourceClientId);
        List<String> methodExpressions = new ArrayList<>();

        if (source instanceof ClientBehaviorHolder && behaviorEvent != null) {
            for (ClientBehavior behavior : ((ClientBehaviorHolder) source).getClientBehaviors().get(behaviorEvent)) {
                List<BehaviorListener> listeners = getField(BehaviorBase.class, List.class, behavior);

                if (listeners != null) {
                    for (BehaviorListener listener : listeners) {
                        MethodExpression methodExpression = getField(listener.getClass(), MethodExpression.class, listener);

                        if (methodExpression != null) {
                            methodExpressions.add(methodExpression.getExpressionString());
                        }
                    }
                }
            }
        }

        if (source instanceof ActionSource2) {
            MethodExpression methodExpression = ((ActionSource2) source).getActionExpression();

            if (methodExpression != null) {
                methodExpressions.add(methodExpression.getExpressionString());
            }
        }

        System.out.println(methodExpressions); // Do your thing with it.
    }

    private static <C, F> F getField(Class<? extends C> classType, Class<F> fieldType, C instance) {
        try {
            for (Field field : classType.getDeclaredFields()) {
                if (field.getType().isAssignableFrom(fieldType)) {
                    field.setAccessible(true);
                    return (F) field.get(instance);
                }
            }
        } catch (Exception e) {
            // Handle?
        }

        return null;
    }

}

In order to get it to run, register as below in faces-config.xml:

<lifecycle>
    <phase-listener>com.example.AjaxActionLoggerPhaseListener</phase-listener>
</lifecycle>

Above is tested and compatible with Mojarra and PrimeFaces and theoretically also compatible with MyFaces.

---

Update: in case you're using JSF utility library OmniFaces, or are open to, since version 2.4 you can use the new Components#getCurrentActionSource() utility method to find out the current action source component and Components#getActionExpressionsAndListeners() to get a list of all action methods and listeners registered on a given component. This is also useable on regular (non-ajax) requests. With that, the above PhaseListener example can be reduced as below:

public class FacesActionLoggerPhaseListener implements PhaseListener {

    @Override
    public PhaseId getPhaseId() {
        return PhaseId.PROCESS_VALIDATIONS;
    }

    @Override
    public void beforePhase(PhaseEvent event) {
        // NOOP.
    }

    @Override
    public void afterPhase(PhaseEvent event) {
        if (!event.getFacesContext().isPostback())) {
            return;
        }

        UIComponent source = Components.getCurrentActionSource();
        List<String> methodExpressions = Components.getActionExpressionsAndListeners(source);
        System.out.println(methodExpressions); // Do your thing with it.
    }

}