site error/access denied on adminTop.action

Can we get a little more details on this? Was the browser logged in and running a existing session? Can this be reproduced? I am also confused as the bug says that the problem happened because of a restart and a restart fixed it...

sorry after a server restart (required due to issues with plosone restart script), we got this error.

after the server restart, we logged in successfully with an admin user, then tried to access adminTop.action, which threw an error.

restarting the plosone service then fixed the problem.

It looks like somehow some stuff got out of sync:

• the SINGLE_SIGNON_USER_KEY entry in the http-session points to AYU0220XVRKQK69DI85DG7L9P6UUDFCQ
• the PLOS_ONE_USER_KEY entry in the http-session points to something that has admin-privs
• request.getUserPrincipal() is returning the anonymous user, i.e. the UserAccountsInterceptor found either null in both request.getRemoteUser() and request.getUserPrincipal(), or it failed to find the given user in the db.

Are the complete logs available somewhere? I need to see more of what went on before.

I don't think Russ will see this till we change ownership.

it certainly pops up immediately when you assign it to me :) can't i get email or rss updates about tickets i've submitted?

which services do you want logs for? i'm attaching plosone and cas.

cas log 6/19

plosone log 6/19

Almost forgot about this one. We need to have a rough idea on why this is happening. Could be hiding a more serious issue.

Replying to russ:

it certainly pops up immediately when you assign it to me :) can't i get email or rss updates about tickets i've submitted?

I thought you created a custom report for yourself - you can get an rss feed for each report (link at the bottom of the page as usual).

which services do you want logs for? i'm attaching plosone and cas.

Sorry, the plosone log is what I needed. Hmm, unfortunately the log you attached doesn't cover the exception you listed here (the log starts on the 19th, whereas the exception occurred on the 18th). I don't know what machine you ran this on, so I can't go get the log myself.

Moving to TBD to prepare to close the milestone.

ah. for some reason i thought it was 6/19. i'll grab 6/18 for you and post.

Ronald will probably only be able to take a look at this as a background task this week as he has to finish up some of the filter framework for CT launch. Hopefully he will have more time next week.

just now, i had this problem after one of the many mulgara restarts.

it then resolved itself without restarting anything after a couple of tries.

2007-07-10 12:57:32,826 DEBUG UserContext> Session is String: org.apache.catalina.session.StandardSessionFacade@1c3d7a16 [TP-Proces
sor158 org.plos.web.UserContext]
2007-07-10 12:57:32,826 DEBUG BaseConfigurableService> ensureInit called by : class org.plos.article.service.ArticleOtmService init
CalledInside is : true [TP-Processor158 org.plos.service.BaseConfigurableService]
2007-07-10 12:57:35,918 WARN  TransactionHelper> rollback failed [TP-Processor158 org.plos.util.TransactionHelper]
org.topazproject.otm.OtmException: error starting transaction
      at org.topazproject.otm.stores.ItqlStore$ItqlStoreConnection.rollback(ItqlStore.java:903)
      at org.topazproject.otm.Transaction.rollback(Transaction.java:84)
      at org.plos.util.TransactionHelper.doInTxE(TransactionHelper.java:90)
      at org.plos.article.service.ArticleOtmService.getArticles(ArticleOtmService.java:509)
      at org.plos.article.service.ArticleOtmService.getArticles(ArticleOtmService.java:318)
      at org.plos.article.service.ArticleOtmService$$FastClassByCGLIB$$45a772ae.invoke(<generated>)
      at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
      at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:674)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:126)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:114)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
      at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:615)
      at org.plos.article.service.ArticleOtmService$$EnhancerByCGLIB$$8cea852e.getArticles(<generated>)
      at org.plos.article.service.FetchArticleService.getArticles(FetchArticleService.java:446)
      at org.plos.article.service.FetchArticleService$$FastClassByCGLIB$$4912ea24.invoke(<generated>)
      at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
      at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:674)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:126)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:114)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
      at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:615)
      at org.plos.article.service.FetchArticleService$$EnhancerByCGLIB$$cfa55324.getArticles(<generated>)
      at org.plos.admin.service.DocumentManagementService.getPublishableFiles(DocumentManagementService.java:400)
      at org.plos.admin.service.DocumentManagementService$$FastClassByCGLIB$$2f0bc3db.invoke(<generated>)
      at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
      at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:674)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:126)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:114)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
      at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:615)
      at org.plos.admin.service.DocumentManagementService$$EnhancerByCGLIB$$665da11b.getPublishableFiles(<generated>)
      at org.plos.admin.action.BaseAdminActionSupport.base(BaseAdminActionSupport.java:36)
      at org.plos.admin.action.AdminTopAction.execute(AdminTopAction.java:20)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at com.opensymphony.xwork.DefaultActionInvocation.invokeAction(DefaultActionInvocation.java:364)
      at com.opensymphony.xwork.DefaultActionInvocation.invokeActionOnly(DefaultActionInvocation.java:216)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:190)
      at org.plos.user.EnsureRoleInterceptor.intercept(EnsureRoleInterceptor.java:47)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at org.plos.user.EnsureUserAccountInterceptor.getReturnCodeDependingOnDisplayName(EnsureUserAccountInterceptor.java:83)
      at org.plos.user.EnsureUserAccountInterceptor.intercept(EnsureUserAccountInterceptor.java:58)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.DefaultWorkflowInterceptor.doIntercept(DefaultWorkflowInterceptor.java:168)
      at com.opensymphony.xwork.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:86)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.validator.ValidationInterceptor.doIntercept(ValidationInterceptor.java:115)
      at com.opensymphony.xwork.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:86)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.webwork.interceptor.FileUploadInterceptor.intercept(FileUploadInterceptor.java:171)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.webwork.interceptor.debugging.DebuggingInterceptor.intercept(DebuggingInterceptor.java:147)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.I18nInterceptor.intercept(I18nInterceptor.java:151)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.TimerInterceptor.invokeUnderTiming(TimerInterceptor.java:131)
      at com.opensymphony.xwork.interceptor.TimerInterceptor.intercept(TimerInterceptor.java:118)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.ExceptionMappingInterceptor.intercept(ExceptionMappingInterceptor.java:186)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.DefaultActionProxy.execute(DefaultActionProxy.java:113)
      at com.opensymphony.webwork.dispatcher.DispatcherUtils.serviceAction(DispatcherUtils.java:225)
      at com.opensymphony.webwork.dispatcher.FilterDispatcher.doFilter(FilterDispatcher.java:202)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      at org.plos.web.InitializeSessionOnLoginFilter.doFilter(InitializeSessionOnLoginFilter.java:74)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      at edu.yale.its.tp.cas.client.filter.CASFilter.doFilter(CASFilter.java:317)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
      at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:199)
      at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:282)
      at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:767)
      at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:697)
      at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:889)
      at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
      at java.lang.Thread.run(Thread.java:595)
Caused by: org.mulgara.query.QueryException: Attempt to rollback transaction outside transaction
      at org.apache.axis.message.SOAPFaultBuilder.createFault(SOAPFaultBuilder.java:222)
      at org.apache.axis.message.SOAPFaultBuilder.endElement(SOAPFaultBuilder.java:129)
      at org.apache.axis.encoding.DeserializationContext.endElement(DeserializationContext.java:1087)
      at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.endElement(AbstractSAXParser.java:633)
      at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.scanEndElement(XMLNSDocumentScannerImpl.java:719)
      at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(XMLDocumentFra
gmentScannerImpl.java:1685)
      at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:
368)
      at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:834)
      at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:764)
      at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:148)
      at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1242)
      at javax.xml.parsers.SAXParser.parse(SAXParser.java:375)
      at org.apache.axis.encoding.DeserializationContext.parse(DeserializationContext.java:227)
      at org.apache.axis.SOAPPart.getAsSOAPEnvelope(SOAPPart.java:696)
      at org.apache.axis.Message.getSOAPEnvelope(Message.java:435)
      at org.apache.axis.handlers.soap.MustUnderstandChecker.invoke(MustUnderstandChecker.java:62)
      at org.apache.axis.client.AxisClient.invoke(AxisClient.java:206)
      at org.apache.axis.client.Call.invokeEngine(Call.java:2784)
      at org.apache.axis.client.Call.invoke(Call.java:2767)
      at org.apache.axis.client.Call.invoke(Call.java:2443)
      at org.apache.axis.client.Call.invoke(Call.java:2366)
      at org.apache.axis.client.Call.invoke(Call.java:1812)
      at org.topazproject.mulgara.itql.service.ItqlInterpreterBeanServicePortSoapBindingStub.rollback(ItqlInterpreterBeanServiceP
ortSoapBindingStub.java:326)
      at org.topazproject.mulgara.itql.ItqlHelper.rollbackTxn(ItqlHelper.java:399)
      at org.topazproject.otm.stores.ItqlStore$ItqlStoreConnection.rollback(ItqlStore.java:901)
      ... 108 more
2007-07-10 12:57:35,919 WARN  UnhandledException> org.topazproject.otm.OtmException: error performing query: select $s $p $o subque
ry (select $t from <local:///topazproject#filter:model=ri> where $o <rdf:type> $t) from <local:///topazproject#filter:model=ri> whe
re $s $p $o and $s <mulgara:is> <info:doi/10.1371/journal.pone.0000563.s024>;select $s $p $o subquery (select $t from <local:///top
azproject#filter:model=ri> where $s <rdf:type> $t) from <local:///topazproject#filter:model=ri> where $s $p $o and $o <mulgara:is>
<info:doi/10.1371/journal.pone.0000563.s024>; [TP-Processor158 org.plos.UnhandledException]
org.plos.ApplicationException: org.topazproject.otm.OtmException: error performing query: select $s $p $o subquery (select $t from
<local:///topazproject#filter:model=ri> where $o <rdf:type> $t) from <local:///topazproject#filter:model=ri> where $s $p $o and $s
<mulgara:is> <info:doi/10.1371/journal.pone.0000563.s024>;select $s $p $o subquery (select $t from <local:///topazproject#filter:mo
del=ri> where $s <rdf:type> $t) from <local:///topazproject#filter:model=ri> where $s $p $o and $o <mulgara:is> <info:doi/10.1371/j
ournal.pone.0000563.s024>;
      at org.plos.article.service.FetchArticleService.getArticles(FetchArticleService.java:463)
      at org.plos.article.service.FetchArticleService$$FastClassByCGLIB$$4912ea24.invoke(<generated>)
      at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
      at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:674)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:126)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:114)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
      at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:615)
      at org.plos.article.service.FetchArticleService$$EnhancerByCGLIB$$cfa55324.getArticles(<generated>)
      at org.plos.admin.service.DocumentManagementService.getPublishableFiles(DocumentManagementService.java:400)
      at org.plos.admin.service.DocumentManagementService$$FastClassByCGLIB$$2f0bc3db.invoke(<generated>)
      at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
      at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:674)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:126)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:114)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
      at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:615)
      at org.plos.admin.service.DocumentManagementService$$EnhancerByCGLIB$$665da11b.getPublishableFiles(<generated>)
      at org.plos.admin.action.BaseAdminActionSupport.base(BaseAdminActionSupport.java:36)
      at org.plos.admin.action.AdminTopAction.execute(AdminTopAction.java:20)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at com.opensymphony.xwork.DefaultActionInvocation.invokeAction(DefaultActionInvocation.java:364)
      at com.opensymphony.xwork.DefaultActionInvocation.invokeActionOnly(DefaultActionInvocation.java:216)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:190)
      at org.plos.user.EnsureRoleInterceptor.intercept(EnsureRoleInterceptor.java:47)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at org.plos.user.EnsureUserAccountInterceptor.getReturnCodeDependingOnDisplayName(EnsureUserAccountInterceptor.java:83)
      at org.plos.user.EnsureUserAccountInterceptor.intercept(EnsureUserAccountInterceptor.java:58)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.DefaultWorkflowInterceptor.doIntercept(DefaultWorkflowInterceptor.java:168)
      at com.opensymphony.xwork.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:86)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.validator.ValidationInterceptor.doIntercept(ValidationInterceptor.java:115)
      at com.opensymphony.xwork.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:86)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.webwork.interceptor.FileUploadInterceptor.intercept(FileUploadInterceptor.java:171)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.webwork.interceptor.debugging.DebuggingInterceptor.intercept(DebuggingInterceptor.java:147)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.I18nInterceptor.intercept(I18nInterceptor.java:151)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:31)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.TimerInterceptor.invokeUnderTiming(TimerInterceptor.java:131)
      at com.opensymphony.xwork.interceptor.TimerInterceptor.intercept(TimerInterceptor.java:118)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.interceptor.ExceptionMappingInterceptor.intercept(ExceptionMappingInterceptor.java:186)
      at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:188)
      at com.opensymphony.xwork.DefaultActionProxy.execute(DefaultActionProxy.java:113)
      at com.opensymphony.webwork.dispatcher.DispatcherUtils.serviceAction(DispatcherUtils.java:225)
      at com.opensymphony.webwork.dispatcher.FilterDispatcher.doFilter(FilterDispatcher.java:202)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      at org.plos.web.InitializeSessionOnLoginFilter.doFilter(InitializeSessionOnLoginFilter.java:74)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      at edu.yale.its.tp.cas.client.filter.CASFilter.doFilter(CASFilter.java:317)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
      at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:199)
      at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:282)
      at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:767)
      at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:697)
      at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:889)
      at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
      at java.lang.Thread.run(Thread.java:595)
Caused by: org.topazproject.otm.OtmException: error performing query: select $s $p $o subquery (select $t from <local:///topazproje
ct#filter:model=ri> where $o <rdf:type> $t) from <local:///topazproject#filter:model=ri> where $s $p $o and $s <mulgara:is> <info:d
oi/10.1371/journal.pone.0000563.s024>;select $s $p $o subquery (select $t from <local:///topazproject#filter:model=ri> where $s <rd
f:type> $t) from <local:///topazproject#filter:model=ri> where $s $p $o and $o <mulgara:is> <info:doi/10.1371/journal.pone.0000563.
s024>;
      at org.topazproject.otm.stores.ItqlStore.get(ItqlStore.java:336)
      at org.topazproject.otm.Session.getFromStore(Session.java:479)
      at org.topazproject.otm.Session.access$100(Session.java:42)
      at org.topazproject.otm.Session$1.invoke(Session.java:661)
      at org.plos.models.ObjectInfo_$$_javassist_15.hashCode(ObjectInfo_$$_javassist_15.java)
      at java.util.HashMap.put(HashMap.java:418)
      at java.util.HashSet.add(HashSet.java:194)
      at org.topazproject.otm.mapping.CollectionMapper.set(CollectionMapper.java:107)
      at org.topazproject.otm.Session.instantiate(Session.java:506)
      at org.topazproject.otm.Session.getFromStore(Session.java:481)
      at org.topazproject.otm.Session.get(Session.java:277)
      at org.topazproject.otm.stores.ItqlStore.list(ItqlStore.java:639)
      at org.topazproject.otm.Session.list(Session.java:410)
      at org.topazproject.otm.Criteria.list(Criteria.java:142)
      at org.plos.article.service.ArticleOtmService.findArticles(ArticleOtmService.java:589)
      at org.plos.article.service.ArticleOtmService.access$000(ArticleOtmService.java:69)
      at org.plos.article.service.ArticleOtmService$4.run(ArticleOtmService.java:512)
      at org.plos.article.service.ArticleOtmService$4.run(ArticleOtmService.java:510)
      at org.plos.util.TransactionHelper.doInTxE(TransactionHelper.java:84)
      at org.plos.article.service.ArticleOtmService.getArticles(ArticleOtmService.java:509)
      at org.plos.article.service.ArticleOtmService.getArticles(ArticleOtmService.java:318)
      at org.plos.article.service.ArticleOtmService$$FastClassByCGLIB$$45a772ae.invoke(<generated>)
      at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
      at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:674)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:126)
      at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:114)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
      at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:615)
      at org.plos.article.service.ArticleOtmService$$EnhancerByCGLIB$$8cea852e.getArticles(<generated>)
      at org.plos.article.service.FetchArticleService.getArticles(FetchArticleService.java:446)
      ... 94 more
Caused by: org.mulgara.query.QueryException: Couldn't build query
      at org.apache.axis.message.SOAPFaultBuilder.createFault(SOAPFaultBuilder.java:222)
      at org.apache.axis.message.SOAPFaultBuilder.endElement(SOAPFaultBuilder.java:129)
      at org.apache.axis.encoding.DeserializationContext.endElement(DeserializationContext.java:1087)
      at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.endElement(AbstractSAXParser.java:633)
      at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.scanEndElement(XMLNSDocumentScannerImpl.java:719)
      at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(XMLDocumentFra
gmentScannerImpl.java:1685)
      at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:
368)
      at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:834)
      at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:764)
      at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:148)
      at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1242)
      at javax.xml.parsers.SAXParser.parse(SAXParser.java:375)
      at org.apache.axis.encoding.DeserializationContext.parse(DeserializationContext.java:227)
      at org.apache.axis.SOAPPart.getAsSOAPEnvelope(SOAPPart.java:696)
      at org.apache.axis.Message.getSOAPEnvelope(Message.java:435)
      at org.apache.axis.handlers.soap.MustUnderstandChecker.invoke(MustUnderstandChecker.java:62)
      at org.apache.axis.client.AxisClient.invoke(AxisClient.java:206)
      at org.apache.axis.client.Call.invokeEngine(Call.java:2784)
      at org.apache.axis.client.Call.invoke(Call.java:2767)
      at org.apache.axis.client.Call.invoke(Call.java:2443)
      at org.apache.axis.client.Call.invoke(Call.java:2366)
      at org.apache.axis.client.Call.invoke(Call.java:1812)
      at org.topazproject.mulgara.itql.service.ItqlInterpreterBeanServicePortSoapBindingStub.executeQueryToString(ItqlInterpreter
BeanServicePortSoapBindingStub.java:358)
      at org.topazproject.mulgara.itql.ItqlHelper.doQuery(ItqlHelper.java:291)
      at org.topazproject.otm.stores.ItqlStore.get(ItqlStore.java:334)
      ... 124 more
2007-07-10 12:57:40,475 DEBUG CASFilter> entering doFilter() [TP-Processor158 edu.yale.its.tp.cas.client.filter.CASFilter]
2007-07-10 12:57:40,475 DEBUG CASFilter> Wrapping request with CASFilterRequestWrapper. [TP-Processor158 edu.yale.its.tp.cas.client
.filter.CASFilter]
2007-07-10 12:57:40,475 DEBUG CASFilterRequestWrapper> wrapping an HttpServletRequest in a CASFilterRequestWrapper. [TP-Processor15
8 edu.yale.its.tp.cas.client.filter.CASFilterRequestWrapper]
2007-07-10 12:57:40,475 DEBUG CASFilter> CAS_FILTER_RECEIPT attribute was present and acceptable - passing  request through filter.
. [TP-Processor158 edu.yale.its.tp.cas.client.filter.CASFilter]
2007-07-10 12:57:40,475 DEBUG InitializeSessionOnLoginFilter> Session is hashCode: 473790998 [TP-Processor158 org.plos.web.Initiali
zeSessionOnLoginFilter]
2007-07-10 12:57:40,475 DEBUG InitializeSessionOnLoginFilter> Session is id: FB8AE70E8CB65959A989AA9A06004BA8 [TP-Processor158 org.
plos.web.InitializeSessionOnLoginFilter]
2007-07-10 12:57:40,475 DEBUG InitializeSessionOnLoginFilter> Session is String: org.apache.catalina.session.StandardSessionFacade@
1c3d7a16 [TP-Processor158 org.plos.web.InitializeSessionOnLoginFilter]
2007-07-10 12:57:40,475 DEBUG InitializeSessionOnLoginFilter> Original Session PGT_IOU_KEY: PGTIOU-143-yhkwg1oSHSl2rxBorA2IzwHlG6as
ZlhZhwN4r8xhUlhEV6Gz37 [TP-Processor158 org.plos.web.InitializeSessionOnLoginFilter]
2007-07-10 12:57:40,475 DEBUG InitializeSessionOnLoginFilter> CAS Receipt is: [edu.yale.its.tp.cas.client.CASReceipt userName=[MLA1
1J1NJUSEF9HGMFF38CTE2MUA308A] casValidateUrl=[https://register.plos.org:/cas/proxyValidate] proxyCallbackUrl=[https://plosone01.loc
aldomain:10443/CasProxyServlet] pgtIou=[PGTIOU-143-yhkwg1oSHSl2rxBorA2IzwHlG6asZlhZhwN4r8xhUlhEV6Gz37] casValidateUrl=[https://regi
ster.plos.org:/cas/proxyValidate] proxyList=[[]]] [TP-Processor158 org.plos.web.InitializeSessionOnLoginFilter]
2007-07-10 12:57:40,475 INFO  LoggingInterceptor> Starting execution stack for action /admin/adminTop [TP-Processor158 com.opensymp
hony.xwork.interceptor.LoggingInterceptor]
2007-07-10 12:57:40,476 DEBUG UserAccountsInterceptor> Changed user to 'info:doi/10.1371/account/6482' using value found in session
-id: FB8AE70E8CB65959A989AA9A06004BA8 [TP-Processor158 org.plos.user.UserAccountsInterceptor]
2007-07-10 12:57:40,476 DEBUG EnsureUserAccountInterceptor> ensure user account interceptor called [TP-Processor158 org.plos.user.E
nsureUserAccountInterceptor]

Can't tell what went wrong here as the underlying exception is only logged at level debug - see #475: need to set the level to debug for org.topazproject.mulgara.ws.ItqlInterpreterBeanWrapper (this is on mulgara).

done, and i'll leave the logging on debug for now.

this seems to resolve itself reliably with a restart, so it's more of a "hey, maybe there's a bug somewhere" than a real problem.

i'll update and reassign if it rears its ugly head again.

i suspect this error happens only when: -plosone is starting up or -plosone home.action page is rebuilding

from what i'm seeing in the logs, i think it's likely the adminTop is causing the same kind of mulgara problems that we saw in 0.7 before the patch.

i will try to reproduce on 0.8 upgrade of dev servers

i think this happens after a plosone restart while the home page is rebuilding (perhaps any time home page is rebuilding?)

will attempt to reproduce on 0.8 and will close if no such luck.

procrastinate

Please do not assign milestones.

there are so many other problems on plosone startup/browse cache refresh that there's no point caring about this.