
walkaround - issue #95
Handle XSRF token expiry more gracefully (or at least make it less noisy in the server logs)
Recently I see a lot more errors on the /channel URI in the wavereactor-hr instance.
Here is the sample exception from the log:
com.google.walkaround.wave.server.servlet.ServerExceptionFilter sendError: ProvisionException; overQuota=false; sending 500: Internal server error com.google.inject.ProvisionException: Guice provision errors:
1) Error in custom provider, com.google.walkaround.util.server.servlet.BadRequestException: com.google.walkaround.wave.server.auth.XsrfHelper$XsrfTokenExpiredException: Token expired: _hc2OPoCDlFkJkBW PXWgL-RU Udw, StableUserId(113484137842605743688), 1e8020fd50a1280887f4bed0c70f7bf2f1e4aeb2 1332313495954 at com.google.walkaround.wave.server.WalkaroundServletModule.provideVerifiedSession(WalkaroundServletModule.java:279) at com.google.walkaround.wave.server.WalkaroundServletModule.provideVerifiedSession(WalkaroundServletModule.java:279) while locating com.google.walkaround.wave.server.ObjectSession for field at com.google.walkaround.wave.server.rpc.ChannelHandler.session(ChannelHandler.java:47) while locating com.google.walkaround.wave.server.rpc.ChannelHandler while locating com.google.walkaround.util.server.servlet.AbstractHandler annotated with @com.google.inject.multibindings.Element(setName=@com.google.walkaround.util.server.servlet.ExactPathHandlers,uniqueId=20)
1 error at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:987) at com.google.inject.spi.ProviderLookup$1.get(ProviderLookup.java:89) at com.google.walkaround.util.server.servlet.HandlerServlet.getHandler(HandlerServlet.java:58) at com.google.walkaround.util.server.servlet.HandlerServlet.doPost(HandlerServlet.java:91) at javax.servlet.http.HttpServlet.service(HttpServlet.java:637) at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:263) at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:178) at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:62) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.walkaround.wave.server.auth.ServletAuthHelper$1.run(ServletAuthHelper.java:211) at com.google.walkaround.wave.server.auth.ServletAuthHelper.serve(ServletAuthHelper.java:184) at com.google.walkaround.wave.server.auth.ServletAuthHelper.filter(ServletAuthHelper.java:209) at com.google.walkaround.wave.server.auth.RpcAuthFilter.doFilter(RpcAuthFilter.java:72) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.walkaround.util.server.servlet.RequestStatsFilter.doFilter(RequestStatsFilter.java:95) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.walkaround.wave.server.servlet.ServerExceptionFilter.doFilter(ServerExceptionFilter.java:121) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.appengine.tools.appstats.AppstatsFilter.doFilter(AppstatsFilter.java:141) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118) at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:102) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388) at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216) at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418) at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:249) at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) at org.mortbay.jetty.Server.handle(Server.java:326) at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923) at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76) at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:135) at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(JavaRuntime.java:446) at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:449) at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:455) at com.google.tracing.TraceContext.runInContext(TraceContext.java:695) at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:333) at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:325) at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:453) at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(ThreadGroupPool.java:251) at java.lang.Thread.run(Thread.java:679) Caused by: com.google.walkaround.util.server.servlet.BadRequestException: com.google.walkaround.wave.server.auth.XsrfHelper$XsrfTokenExpiredException: Token expired: _hc2OPoCDlFkJkBW PXWgL-RU Udw, StableUserId(113484137842605743688), 1e8020fd50a1280887f4bed0c70f7bf2f1e4aeb2 1332313495954 at com.google.walkaround.wave.server.WalkaroundServletModule.provideVerifiedSession(WalkaroundServletModule.java:283) at sun.reflect.GeneratedMethodAccessor30.invoke(Unknown Source) <continued in next message> E 2012-04-06 12:32:12.137 <continued from previous message> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:43) at com.google.inject.internal.ProviderMethod.get(ProviderMethod.java:104) at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40) at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46) at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031) at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40) at com.google.inject.servlet.ServletScopes$1$1.get(ServletScopes.java:88) at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40) at com.google.inject.internal.SingleFieldInjector.inject(SingleFieldInjector.java:53) at com.google.inject.internal.MembersInjectorImpl.injectMembers(MembersInjectorImpl.java:110) at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:94) at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254) at com.google.inject.internal.FactoryProxy.get(FactoryProxy.java:54) at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978) at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1024) at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974) at com.google.inject.spi.ProviderLookup$1.get(ProviderLookup.java:89) at com.google.walkaround.util.server.servlet.HandlerServlet.getHandler(HandlerServlet.java:58) at com.google.walkaround.util.server.servlet.HandlerServlet.doPost(HandlerServlet.java:91) at javax.servlet.http.HttpServlet.service(HttpServlet.java:637) at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:263) at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:178) at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:62) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.walkaround.wave.server.auth.ServletAuthHelper$1.run(ServletAuthHelper.java:211) at com.google.walkaround.wave.server.auth.ServletAuthHelper.serve(ServletAuthHelper.java:184) at com.google.walkaround.wave.server.auth.ServletAuthHelper.filter(ServletAuthHelper.java:209) at com.google.walkaround.wave.server.auth.RpcAuthFilter.doFilter(RpcAuthFilter.java:72) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.walkaround.util.server.servlet.RequestStatsFilter.doFilter(RequestStatsFilter.java:95) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.walkaround.wave.server.servlet.ServerExceptionFilter.doFilter(ServerExceptionFilter.java:121) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.appengine.tools.appstats.AppstatsFilter.doFilter(AppstatsFilter.java:141) at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118) at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388) at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216) at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418) at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) at org.mortbay.jetty.Server.handle(Server.java:326) at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923) at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:449) at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:455) at com.google.tracing.TraceContext.runInContext(TraceContext.java:695) at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:333) at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:325) at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:453) ... 1 more Caused by: com.google.walkaround.wave.server.auth.XsrfHelper$XsrfTokenExpiredException: Token expired: _hc2OPoCDlFkJkBW PXWgL-RU Udw, StableUserId(113484137842605743688), 1e8020fd50a1280887f4bed0c70f7bf2f1e4aeb2 1332313495954 at com.google.walkaround.wave.server.auth.XsrfHelper.verify(XsrfHelper.java:97) at com.google.walkaround.wave.server.ObjectSessionHelper.getVerifiedSession(ObjectSessionHelper.java:84) at com.google.walkaround.wave.server.WalkaroundServletModule.provideVerifiedSession(WalkaroundServletModule.java:279) ... 83 more
Comment #1
Posted on Apr 6, 2012 by Quick Lion"Token expired" on /channel means that someone had a wave open in their browser for more than two weeks without reloading or switching to a different wave; this is not currently supported. The wave will be disconnected, and the user will see a message telling them to reload. The stack trace you sent refers to the timestamp 1332313495954, which means someone was trying to work with a wave that they opened on Wed Mar 21 00:04:55 PDT 2012 in their browser.
We should probably make this less noisy in the logs if it makes real errors harder to see.
Making it possible to keep a wave open for longer could be as simple as changing xsrf_token_expiry_seconds in flags.json, but it has security implications. Maybe 30 days would still be OK and make it less likely to occur, but that's a guess.
Comment #2
Posted on Apr 20, 2012 by Quick Lion(No comment was entered for this change.)
Status: Accepted
Labels:
Type-Defect
Priority-Medium