ICEfaces
  1. ICEfaces
  2. ICE-1900

warning messages to server that state problems exist in application (no noticeable functional deficiencies though)

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 1.6
    • Fix Version/s: 1.8.2-RC1, 1.8.2
    • Component/s: Framework
    • Labels:
      None
    • Environment:
      Seam 2.0.0.beta1, jsf1.2 and Icefaces1.6.0 as well as head

      Description

      warning messages get printed to server log

       15:40:03,946 WARN [Parameters] Parameters: Invalid chunk ignored.
       15:40:07,174 INFO [lifecycle] WARNING: FacesMessage(s) have been
        enqueued, but may not have been displayed.

      yet the faces messages are displayed.

        Activity

        Hide
        Tyler Johnson added a comment - - edited

        Test case intended for deployment on Tomcat 6. It is a standard ICEfaces project with no additional libraries used.

        Show
        Tyler Johnson added a comment - - edited Test case intended for deployment on Tomcat 6. It is a standard ICEfaces project with no additional libraries used.
        Hide
        Deryk Sinotte added a comment -

        So the problem appears to be this:

        The Sun RI basically makes use of the interaction between 3 things.

        1) The FacesContext (implemented by FacesContextImpl and BridgeFacesContext) which provides the API for adding and getting the FacesMessages.
        2) The com.sun.faces.util.RequestStateManager which is an internal utility for storing and retrieving "private" request-scoped attributes.
        3) The RenderResponsePhase which does some message processing before and after the view is rendered.

        Here's the relevant code from RenderResponsePhase.execute:

        try {
        //Setup message display LOGGER.
        if (LOGGER.isLoggable(Level.INFO)) {
        Iterator<String> clientIdIter = facesContext.getClientIdsWithMessages();

        //If Messages are queued
        if (clientIdIter.hasNext()) {
        Set<String> clientIds = new HashSet<String>();

        //Copy client ids to set of clientIds pending display.
        while (clientIdIter.hasNext())

        { clientIds.add(clientIdIter.next()); }

        RequestStateManager.set(facesContext,
        RequestStateManager.CLIENT_ID_MESSAGES_NOT_DISPLAYED,
        clientIds);
        }
        }

        //render the view
        facesContext.getApplication().getViewHandler().
        renderView(facesContext, facesContext.getViewRoot());

        //display results of message display LOGGER
        if (LOGGER.isLoggable(Level.INFO) &&
        RequestStateManager.containsKey(facesContext,
        RequestStateManager.CLIENT_ID_MESSAGES_NOT_DISPLAYED)) {

        //remove so Set does not get modified when displaying messages.
        Set<String> clientIds = TypedCollections.dynamicallyCastSet(
        (Set) RequestStateManager.remove(facesContext,
        RequestStateManager.CLIENT_ID_MESSAGES_NOT_DISPLAYED),
        String.class);
        if (!clientIds.isEmpty()) {

        //Display each message possibly not displayed.
        StringBuilder builder = new StringBuilder();
        for (String clientId : clientIds) {
        Iterator<FacesMessage> messages = facesContext.getMessages(clientId);
        while (messages.hasNext())

        { FacesMessage message = messages.next(); builder.append("\n"); builder.append("sourceId=").append(clientId); builder.append("[severity=(").append(message.getSeverity()); builder.append("), summary=(").append(message.getSummary()); builder.append("), detail=(").append(message.getDetail()).append(")]"); }

        }
        LOGGER.log(Level.INFO, "jsf.non_displayed_message", builder.toString());
        }
        }
        } catch (IOException e)

        { throw new FacesException(e.getMessage(), e); }

        In the RenderResponsePhase, before rendering the view, it retrieves all the messages for the pending client ids with messages and adds them to the RequestStateManager. After the view has been rendered, it checks to see if any of those entries are still there. The actual logic for clearing these pending ids is in the FacesContextImpl.getMessage and getMessages methods. It calls the RequestStateManager to return the pending message(s) and additionally clears it/them.

        One of the oddities is that the logic in the RenderResponsePhase is all wrapped in LOGGER.isLoggable(Level.INFO) checks. So none of this will happen if the logging level is set higher. The other oddity is that the act of adding the messages doesn't invoke the RequestStateManager at all so our own BridgeFacesContext does all the message handling fine. It's just that when we retrieve the messages for display, we aren't clearing out this secret stash of messages that was only added by the RenderResponsePhase because of a certain logging level.

        Not sure of the best way to fix this as it's not really a functional problem per se. More of a logging anomaly that's relying on secret information to guess that something 'might' be going wrong. The 'WARNING' is actually part of the LogStrings.properties file for the message and not actually the logging level (which is INFO).

        Show
        Deryk Sinotte added a comment - So the problem appears to be this: The Sun RI basically makes use of the interaction between 3 things. 1) The FacesContext (implemented by FacesContextImpl and BridgeFacesContext) which provides the API for adding and getting the FacesMessages. 2) The com.sun.faces.util.RequestStateManager which is an internal utility for storing and retrieving "private" request-scoped attributes. 3) The RenderResponsePhase which does some message processing before and after the view is rendered. Here's the relevant code from RenderResponsePhase.execute: try { //Setup message display LOGGER. if (LOGGER.isLoggable(Level.INFO)) { Iterator<String> clientIdIter = facesContext.getClientIdsWithMessages(); //If Messages are queued if (clientIdIter.hasNext()) { Set<String> clientIds = new HashSet<String>(); //Copy client ids to set of clientIds pending display. while (clientIdIter.hasNext()) { clientIds.add(clientIdIter.next()); } RequestStateManager.set(facesContext, RequestStateManager.CLIENT_ID_MESSAGES_NOT_DISPLAYED, clientIds); } } //render the view facesContext.getApplication().getViewHandler(). renderView(facesContext, facesContext.getViewRoot()); //display results of message display LOGGER if (LOGGER.isLoggable(Level.INFO) && RequestStateManager.containsKey(facesContext, RequestStateManager.CLIENT_ID_MESSAGES_NOT_DISPLAYED)) { //remove so Set does not get modified when displaying messages. Set<String> clientIds = TypedCollections.dynamicallyCastSet( (Set) RequestStateManager.remove(facesContext, RequestStateManager.CLIENT_ID_MESSAGES_NOT_DISPLAYED), String.class); if (!clientIds.isEmpty()) { //Display each message possibly not displayed. StringBuilder builder = new StringBuilder(); for (String clientId : clientIds) { Iterator<FacesMessage> messages = facesContext.getMessages(clientId); while (messages.hasNext()) { FacesMessage message = messages.next(); builder.append("\n"); builder.append("sourceId=").append(clientId); builder.append("[severity=(").append(message.getSeverity()); builder.append("), summary=(").append(message.getSummary()); builder.append("), detail=(").append(message.getDetail()).append(")]"); } } LOGGER.log(Level.INFO, "jsf.non_displayed_message", builder.toString()); } } } catch (IOException e) { throw new FacesException(e.getMessage(), e); } In the RenderResponsePhase, before rendering the view, it retrieves all the messages for the pending client ids with messages and adds them to the RequestStateManager. After the view has been rendered, it checks to see if any of those entries are still there. The actual logic for clearing these pending ids is in the FacesContextImpl.getMessage and getMessages methods. It calls the RequestStateManager to return the pending message(s) and additionally clears it/them. One of the oddities is that the logic in the RenderResponsePhase is all wrapped in LOGGER.isLoggable(Level.INFO) checks. So none of this will happen if the logging level is set higher. The other oddity is that the act of adding the messages doesn't invoke the RequestStateManager at all so our own BridgeFacesContext does all the message handling fine. It's just that when we retrieve the messages for display, we aren't clearing out this secret stash of messages that was only added by the RenderResponsePhase because of a certain logging level. Not sure of the best way to fix this as it's not really a functional problem per se. More of a logging anomaly that's relying on secret information to guess that something 'might' be going wrong. The 'WARNING' is actually part of the LogStrings.properties file for the message and not actually the logging level (which is INFO).
        Hide
        Deryk Sinotte added a comment -

        I've checked in a new class that reflectively detects if the Sun's RequestStateManager is available. If it is, the same logic is applied to remove pending messages.

        Show
        Deryk Sinotte added a comment - I've checked in a new class that reflectively detects if the Sun's RequestStateManager is available. If it is, the same logic is applied to remove pending messages.
        Hide
        Neil Griffin added a comment -

        The new ICEfaces RequestStateManagerDelegate.clearMessages(FacesContext fc, String clientID) method is only working for messages associated with a component. The "FacesMessage(s) have been enqueued" annoyance is still happening for GLOBAL messages (where clientID == null).

        Request that the "if" condition in the clearMessages method be changed to the following, so that it clears out GLOBAL messages too:

        public static void clearMessages(FacesContext fc, String clientID) {

        // if (!detected || fc == null || clientID == null) {
        if (!detected || fc == null)

        { return; }

        Set pendingMessageIds = getPendingMessageIds(fc);
        if (pendingMessageIds != null && !pendingMessageIds.isEmpty())

        { pendingMessageIds.remove(clientID); }

        }

        Show
        Neil Griffin added a comment - The new ICEfaces RequestStateManagerDelegate.clearMessages(FacesContext fc, String clientID) method is only working for messages associated with a component. The "FacesMessage(s) have been enqueued" annoyance is still happening for GLOBAL messages (where clientID == null). Request that the "if" condition in the clearMessages method be changed to the following, so that it clears out GLOBAL messages too: public static void clearMessages(FacesContext fc, String clientID) { // if (!detected || fc == null || clientID == null) { if (!detected || fc == null) { return; } Set pendingMessageIds = getPendingMessageIds(fc); if (pendingMessageIds != null && !pendingMessageIds.isEmpty()) { pendingMessageIds.remove(clientID); } }
        Hide
        Ken Fyten added a comment -

        Neil,

        As this JIRA is already closed (and related changes released in a prior version), I've created a new JIRA for the follow-up issue that you've reported above. See ICE-5177 for future reference on the issue.

        Show
        Ken Fyten added a comment - Neil, As this JIRA is already closed (and related changes released in a prior version), I've created a new JIRA for the follow-up issue that you've reported above. See ICE-5177 for future reference on the issue.

          People

          • Assignee:
            Deryk Sinotte
            Reporter:
            Judy Guglielmin
          • Votes:
            4 Vote for this issue
            Watchers:
            6 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: