You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@myfaces.apache.org by gc...@apache.org on 2011/08/26 04:50:51 UTC
svn commit: r1161970 - in
/myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal:
application/StateManagerImpl.java util/TokenCache.java
util/TokenCacheDebugUtils.java
Author: gcrawford
Date: Fri Aug 26 02:50:50 2011
New Revision: 1161970
URL: http://svn.apache.org/viewvc?rev=1161970&view=rev
Log:
TRINIDAD-2131 Make it easier to debug viewExpiredExceptions
Added:
myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCacheDebugUtils.java
Modified:
myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/application/StateManagerImpl.java
myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCache.java
Modified: myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/application/StateManagerImpl.java
URL: http://svn.apache.org/viewvc/myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/application/StateManagerImpl.java?rev=1161970&r1=1161969&r2=1161970&view=diff
==============================================================================
--- myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/application/StateManagerImpl.java (original)
+++ myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/application/StateManagerImpl.java Fri Aug 26 02:50:50 2011
@@ -60,6 +60,7 @@ import org.apache.myfaces.trinidadintern
import org.apache.myfaces.trinidadinternal.util.ObjectInputStreamResolveClass;
import org.apache.myfaces.trinidadinternal.util.SubKeyMap;
import org.apache.myfaces.trinidadinternal.util.TokenCache;
+import org.apache.myfaces.trinidadinternal.util.TokenCacheDebugUtils;
/**
@@ -621,10 +622,29 @@ public class StateManagerImpl extends St
// get bumped up to the front in the LRU Cache!
boolean isAvailable = _getViewCache(trinContext, extContext).isAvailable((String) token);
assert ((viewState != null) == isAvailable);
-
+
if (viewState == null)
{
_LOG.severe("CANNOT_FIND_SAVED_VIEW_STATE", token);
+
+ if(TokenCacheDebugUtils.debugTokenCache())
+ {
+ TokenCacheDebugUtils.clearRequestStringBuffer();
+ TokenCacheDebugUtils.addToRequestStringBuffer("-------------- Restore View ----------\n");
+ TokenCacheDebugUtils.logIdString();
+
+ // get view cache key with "." separator suffix to separate the SubKeyMap keys
+ String subkey = _getViewCacheKey(extContext,
+ RequestContext.getCurrentInstance(),
+ _SUBKEY_SEPARATOR);
+
+ Map<String, PageState> stateMap = new SubKeyMap<PageState>(
+ extContext.getSessionMap(),
+ subkey);
+ TokenCacheDebugUtils.logCacheInfo(stateMap, null, "token '" + token + "' not found");
+ _LOG.severe(TokenCacheDebugUtils.getRequestString());
+ }
+
return null;
}
Modified: myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCache.java
URL: http://svn.apache.org/viewvc/myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCache.java?rev=1161970&r1=1161969&r2=1161970&view=diff
==============================================================================
--- myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCache.java (original)
+++ myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCache.java Fri Aug 26 02:50:50 2011
@@ -26,14 +26,10 @@ import java.security.NoSuchAlgorithmExce
import java.security.SecureRandom;
import java.util.Map;
-
import java.util.concurrent.ConcurrentHashMap;
-
import java.util.concurrent.atomic.AtomicLong;
-import javax.faces.component.UIViewRoot;
import javax.faces.context.ExternalContext;
-import javax.faces.context.FacesContext;
import org.apache.myfaces.trinidad.logging.TrinidadLogger;
@@ -235,14 +231,19 @@ public class TokenCache implements Seria
// in _removed being non-null afterwards
_cache.put(token, token);
- if(_DEBUG_TOKEN_CACHE)
+ if(TokenCacheDebugUtils.debugTokenCache())
{
- _LOG.severe("-------------- Add New Entry ----------");
- _debugAddTokenToViewIdMap(token);
+ TokenCacheDebugUtils.clearRequestStringBuffer();
+ TokenCacheDebugUtils.addToRequestStringBuffer("-------------- Add New Entry ----------\n");
+ TokenCacheDebugUtils.logIdString();
+ TokenCacheDebugUtils.addTokenToViewIdMap(token);
if (pinnedToken != null)
{
- _LOG.severe("PINNING " + _debugGetTokenToViewIdString(_debugGetTokenToViewIdMap(), token) + " to " + _debugGetTokenToViewIdString(_debugGetTokenToViewIdMap(), pinnedToken) );
+ TokenCacheDebugUtils.addToRequestStringBuffer("\nPINNING " +
+ TokenCacheDebugUtils.getTokenToViewIdString(TokenCacheDebugUtils.getTokenToViewIdMap(), token) +
+ " to " +
+ TokenCacheDebugUtils.getTokenToViewIdString(TokenCacheDebugUtils.getTokenToViewIdMap(), pinnedToken));
}
}
@@ -262,9 +263,10 @@ public class TokenCache implements Seria
// our contents have changed, so mark ourselves as dirty in our owner
_dirty();
- if(_DEBUG_TOKEN_CACHE)
+ if(TokenCacheDebugUtils.debugTokenCache())
{
- _debugLogCacheInfo(targetStore, "After Additions");
+ TokenCacheDebugUtils.logCacheInfo(targetStore, _pinned, "After Additions");
+ _LOG.severe(TokenCacheDebugUtils.getRequestString());
}
@@ -308,9 +310,9 @@ public class TokenCache implements Seria
_LOG.finest("Removing token ''{0}''", token);
// Remove it from the target store
- if (_DEBUG_TOKEN_CACHE)
+ if (TokenCacheDebugUtils.debugTokenCache())
{
- _debugRemoveTokenFromViewIdMap(token);
+ TokenCacheDebugUtils.removeTokenFromViewIdMap(token);
}
removedValue = targetStore.remove(token);
@@ -319,10 +321,10 @@ public class TokenCache implements Seria
if (wasPinned != null)
{
- if (_DEBUG_TOKEN_CACHE)
+ if (TokenCacheDebugUtils.debugTokenCache())
{
- _LOG.severe("REMOVING pinning of token " + token + " to " +
- _debugGetTokenToViewIdString(_debugGetTokenToViewIdMap(), wasPinned) );
+ TokenCacheDebugUtils.addToRequestStringBuffer("\nREMOVING pinning of token " + token + " to " +
+ TokenCacheDebugUtils.getTokenToViewIdString(TokenCacheDebugUtils.getTokenToViewIdMap(), wasPinned));
}
// Yup, so see if we can remove that token
@@ -331,10 +333,10 @@ public class TokenCache implements Seria
}
else
{
- if (_DEBUG_TOKEN_CACHE)
+ if (TokenCacheDebugUtils.debugTokenCache())
{
- _LOG.severe("NOT removing pinned token from target store " +
- _debugGetTokenToViewIdString(_debugGetTokenToViewIdMap(), token) );
+ TokenCacheDebugUtils.addToRequestStringBuffer("\nNOT removing pinned token from target store " +
+ TokenCacheDebugUtils.getTokenToViewIdString(TokenCacheDebugUtils.getTokenToViewIdMap(), token) );
}
_LOG.finest("Not removing pinned token ''{0}''", token);
@@ -359,9 +361,11 @@ public class TokenCache implements Seria
synchronized (this)
{
- if(_DEBUG_TOKEN_CACHE)
+ if(TokenCacheDebugUtils.debugTokenCache())
{
- _LOG.severe("-------------- Remove Old Entry ----------");
+ TokenCacheDebugUtils.clearRequestStringBuffer();
+ TokenCacheDebugUtils.addToRequestStringBuffer("-------------- Remove Old Entry ----------\n");
+ TokenCacheDebugUtils.logIdString();
}
_LOG.finest("Removing token {0} from cache", token);
@@ -371,9 +375,10 @@ public class TokenCache implements Seria
// Or should it stay in memory?
oldValue = _removeTokenIfReady(targetStore, token);
- if (_DEBUG_TOKEN_CACHE)
+ if (TokenCacheDebugUtils.debugTokenCache())
{
- _debugLogCacheInfo(targetStore, "After removing old entry:");
+ TokenCacheDebugUtils.logCacheInfo(targetStore, _pinned, "After removing old entry:");
+ _LOG.severe(TokenCacheDebugUtils.getRequestString());
}
}
@@ -423,97 +428,6 @@ public class TokenCache implements Seria
}
}
-
- /**
- * Method to help with debugging, should only be called when
- * _DEBUG_TOKEN_CACHE is true
- */
- private void _debugAddTokenToViewIdMap(String token)
- {
- FacesContext context = FacesContext.getCurrentInstance();
- Map<String,String> tokenToViewIdMap = _debugGetTokenToViewIdMap();
- UIViewRoot root = context.getViewRoot();
- String viewId = root.getViewId();
- tokenToViewIdMap.put(token, viewId);
- _LOG.severe("ADDING " + _debugGetTokenToViewIdString(tokenToViewIdMap, token));
- }
-
- /**
- * Method to help with debugging, should only be called when
- * _DEBUG_TOKEN_CACHE is true
- */
- private void _debugRemoveTokenFromViewIdMap(String token)
- {
- FacesContext context = FacesContext.getCurrentInstance();
- Map<String,String> tokenToViewIdMap = _debugGetTokenToViewIdMap();
-
- _LOG.severe("REMOVING " + _debugGetTokenToViewIdString(tokenToViewIdMap, token));
- tokenToViewIdMap.remove(token);
- }
-
-
- /**
- * Method to help with debugging, should only be called when
- * _DEBUG_TOKEN_CACHE is true
- */
- private String _debugGetTokenToViewIdString(Map<String,String> tokenToViewId, String token)
- {
- StringBuffer tokenBuffer = new StringBuffer();
- tokenBuffer.append(token);
- tokenBuffer.append(" (");
- tokenBuffer.append(tokenToViewId.get(token));
- tokenBuffer.append(")");
-
- return tokenBuffer.toString();
- }
-
- /**
- * Method to help with debugging, should only be called when
- * _DEBUG_TOKEN_CACHE is true
- */
- private <V> void _debugLogCacheInfo(Map<String, V> targetStore, String logAddition)
- {
- Map<String,String> tokenToViewId = _debugGetTokenToViewIdMap();
- StringBuffer logString = new StringBuffer();
-
- logString.append(logAddition);
- logString.append("\ntarget Store token keys:");
-
- for (String targetStoreToken: targetStore.keySet())
- {
- logString.append("\n ");
- logString.append(_debugGetTokenToViewIdString(tokenToViewId, targetStoreToken));
- }
-
- logString.append("\n_pinned:");
-
- for (String pinnedKeyToken: _pinned.keySet())
- {
- logString.append("\n ");
- logString.append(_debugGetTokenToViewIdString(tokenToViewId, pinnedKeyToken));
-
- logString.append(" pinned to ");
- String pinnedValueToken = _pinned.get(pinnedKeyToken);
- logString.append(_debugGetTokenToViewIdString(tokenToViewId, pinnedValueToken));
- }
-
- _LOG.severe(logString.toString());
- }
-
- private Map<String,String> _debugGetTokenToViewIdMap()
- {
- FacesContext context = FacesContext.getCurrentInstance();
- Map<String,String> tokenToViewId = (Map<String, String>)context.getExternalContext().getSessionMap().get("org.apache.myfaces.trinidadinternal.util.TOKEN_FOR_VIEW_ID");
-
- if (tokenToViewId == null)
- {
- tokenToViewId = new ConcurrentHashMap<String, String>();
- context.getExternalContext().getSessionMap().put("org.apache.myfaces.trinidadinternal.util.TOKEN_FOR_VIEW_ID", tokenToViewId);
-
- }
- return tokenToViewId;
- }
-
private class LRU extends LRUCache<String, String>
{
public LRU(int maxSize)
@@ -553,21 +467,4 @@ public class TokenCache implements Seria
static private final long serialVersionUID = 1L;
static private final TrinidadLogger _LOG =
TrinidadLogger.createTrinidadLogger(TokenCache.class);
-
- // ViewExpiredExceptions are fairly common, and the token cache is used for
- // page state tokens, but the tokens aren't really human readable.
- // In order to make it easier to understand what is in the cache
- // we've added a system property for debugging purposes. When enabled
- // we store a map of token -> viewId on the session which we use
- // to log something more human readable.
- //
- // in order to use this the tester would set the system property to:
- // -Dorg.apache.myfaces.trinidadinternal.DEBUG_TOKEN_CACHE=true
-
- static private final Boolean _DEBUG_TOKEN_CACHE;
- static
- {
- String dtcProp = System.getProperty("org.apache.myfaces.trinidadinternal.DEBUG_TOKEN_CACHE");
- _DEBUG_TOKEN_CACHE = Boolean.valueOf(dtcProp);
- }
}
Added: myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCacheDebugUtils.java
URL: http://svn.apache.org/viewvc/myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCacheDebugUtils.java?rev=1161970&view=auto
==============================================================================
--- myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCacheDebugUtils.java (added)
+++ myfaces/trinidad/trunk/trinidad-impl/src/main/java/org/apache/myfaces/trinidadinternal/util/TokenCacheDebugUtils.java Fri Aug 26 02:50:50 2011
@@ -0,0 +1,268 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package org.apache.myfaces.trinidadinternal.util;
+
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+
+import javax.faces.component.UIViewRoot;
+import javax.faces.context.ExternalContext;
+import javax.faces.context.FacesContext;
+
+import javax.servlet.http.HttpSession;
+
+import org.apache.myfaces.trinidad.context.RequestContext;
+import org.apache.myfaces.trinidad.context.WindowManager;
+
+
+public final class TokenCacheDebugUtils
+{
+
+ private TokenCacheDebugUtils(){}
+
+
+ /**
+ * Checks whether we are debugging the token cache.
+ * No other method in TokenCacheDebugUtils should be called unless this method returns true.
+ */
+ public static Boolean debugTokenCache()
+ {
+ return _DEBUG_TOKEN_CACHE;
+ }
+
+ /**
+ * Method to help with debugging, should only be called when
+ * debugTokenCache() is true
+ */
+ public static void addTokenToViewIdMap(String token)
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+ FacesContext context = FacesContext.getCurrentInstance();
+ Map<String,String> tokenToViewIdMap = getTokenToViewIdMap();
+ UIViewRoot root = context.getViewRoot();
+ String viewId = root.getViewId();
+ tokenToViewIdMap.put(token, viewId);
+
+ addToRequestStringBuffer("\nADDING " + getTokenToViewIdString(tokenToViewIdMap, token));
+ }
+
+ /**
+ * Method to help with debugging, should only be called when
+ * debugTokenCache() is true
+ */
+ public static void removeTokenFromViewIdMap(String token)
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+ Map<String,String> tokenToViewIdMap = getTokenToViewIdMap();
+
+ addToRequestStringBuffer("\nREMOVING " + getTokenToViewIdString(tokenToViewIdMap, token));
+ tokenToViewIdMap.remove(token);
+ }
+
+
+ /**
+ * Method to help with debugging, should only be called when
+ * debugTokenCache() is true
+ */
+ public static String getTokenToViewIdString(Map<String,String> tokenToViewId, String token)
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+ StringBuffer tokenBuffer = new StringBuffer();
+ tokenBuffer.append(token);
+ tokenBuffer.append(" (");
+ tokenBuffer.append(tokenToViewId.get(token));
+ tokenBuffer.append(")");
+
+ return tokenBuffer.toString();
+ }
+
+ /**
+ * Method to help with debugging, should only be called when
+ * debugTokenCache() is true
+ */
+ public static <V> void logCacheInfo(Map<String, V> targetStore, Map<String, String> pinned, String logAddition)
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+ Map<String,String> tokenToViewId = getTokenToViewIdMap();
+ StringBuffer logString = new StringBuffer();
+
+ if (logAddition != null)
+ {
+ logString.append(logAddition).append("\n");
+ }
+
+ logString.append("cached token keys:");
+
+ for (String targetStoreToken: targetStore.keySet())
+ {
+ logString.append("\n ");
+ logString.append(getTokenToViewIdString(tokenToViewId, targetStoreToken));
+ }
+
+ if (pinned != null)
+ {
+ logString.append("\n_pinned token keys:");
+
+ for (String pinnedKeyToken: pinned.keySet())
+ {
+ logString.append("\n ");
+ logString.append(getTokenToViewIdString(tokenToViewId, pinnedKeyToken));
+
+ logString.append(" pinned to ");
+ String pinnedValueToken = pinned.get(pinnedKeyToken);
+ logString.append(getTokenToViewIdString(tokenToViewId, pinnedValueToken));
+ }
+ }
+
+ addToRequestStringBuffer("\n" + logString.toString());
+ }
+
+ /**
+ * Method to help with debugging, should only be called when
+ * debugTokenCache() is true
+ */
+ public static Map<String,String> getTokenToViewIdMap()
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+ FacesContext context = FacesContext.getCurrentInstance();
+ Map<String,String> tokenToViewId = (Map<String, String>)context.getExternalContext().getSessionMap().get("org.apache.myfaces.trinidadinternal.util.TOKEN_FOR_VIEW_ID");
+
+ if (tokenToViewId == null)
+ {
+ tokenToViewId = new ConcurrentHashMap<String, String>();
+ context.getExternalContext().getSessionMap().put("org.apache.myfaces.trinidadinternal.util.TOKEN_FOR_VIEW_ID", tokenToViewId);
+
+ }
+ return tokenToViewId;
+ }
+
+ /**
+ * Method to help with debugging, should only be called when
+ * debugTokenCache() is true
+ */
+ public static void logIdString()
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+
+ ExternalContext externalContext = FacesContext.getCurrentInstance().getExternalContext();
+ String sessionId = "";
+ Object session = externalContext.getSession(false);
+
+ if (session instanceof HttpSession)
+ {
+ sessionId = ((HttpSession)session).getId();
+ }
+
+ addToRequestStringBuffer("Session Id = " + sessionId);
+
+ WindowManager wm = RequestContext.getCurrentInstance().getWindowManager();
+ String windowId = wm.getCurrentWindow(externalContext).getId();
+ addToRequestStringBuffer("\nWindow Id = " + windowId );
+ }
+
+ /**
+ * Method to help with debugging, should only be called when
+ * debugTokenCache() is true
+ */
+ public static void addToRequestStringBuffer(String addString)
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+ _getRequestStringBuffer().append(addString);
+ }
+
+
+ /**
+ * Method to help with debugging, should only be called when
+ * debugTokenCache() is true
+ */
+ public static void clearRequestStringBuffer()
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+ Map<String, Object> requestMap = FacesContext.getCurrentInstance().getExternalContext().getRequestMap();
+ requestMap.put("org.apache.myfaces.trinidadinternal.DEBUG_TOKEN_CACHE.StringBuffer", null);
+ }
+
+ /**
+ * Method to help with debugging, should only be called when
+ * debugTokenCache() is true
+ */
+ public static String getRequestString()
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+ return _getRequestStringBuffer().toString();
+ }
+
+ private static StringBuffer _getRequestStringBuffer()
+ {
+ if (!_DEBUG_TOKEN_CACHE)
+ throw new UnsupportedOperationException(_UNSUPPORTED_OPERATION_MESSAGE);
+
+ Map<String, Object> requestMap = FacesContext.getCurrentInstance().getExternalContext().getRequestMap();
+ StringBuffer buff = (StringBuffer)requestMap.get("org.apache.myfaces.trinidadinternal.DEBUG_TOKEN_CACHE.StringBuffer");
+
+ if ( buff == null)
+ {
+ buff = new StringBuffer();
+ requestMap.put("org.apache.myfaces.trinidadinternal.DEBUG_TOKEN_CACHE.StringBuffer", buff);
+ }
+
+ return buff;
+ }
+
+ private static final String _UNSUPPORTED_OPERATION_MESSAGE =
+ "Methods in TokenCacheDebugUtils can only be called when " +
+ "TokenCacheDebugUtils.debugTokenCache() returns true. " +
+ "TokenCacheDebugUtils.debugTokenCache() returns true when the system property " +
+ "'org.apache.myfaces.trinidadinternal.DEBUG_TOKEN_CACHE' is true";
+
+ // ViewExpiredExceptions are fairly common, and the token cache is used for
+ // page state tokens, but the tokens aren't really human readable.
+ // In order to make it easier to understand what is in the cache
+ // we've added a system property for debugging purposes. When enabled
+ // we store a map of token -> viewId on the session which we use
+ // to log something more human readable.
+ //
+ // in order to use this the tester would set the system property to:
+ // -Dorg.apache.myfaces.trinidadinternal.DEBUG_TOKEN_CACHE=true
+
+ static private final Boolean _DEBUG_TOKEN_CACHE;
+ static
+ {
+ String dtcProp = System.getProperty("org.apache.myfaces.trinidadinternal.DEBUG_TOKEN_CACHE");
+ _DEBUG_TOKEN_CACHE = Boolean.valueOf(dtcProp);
+ }
+}