Uploaded image for project: 'XWiki Platform'
  1. XWiki Platform
  2. XWIKI-8747

Occasional stacktrace in the console when using the Applications section in Administration (trying to get the page lock with js)

    Details

    • Difficulty:
      Medium
    • Documentation:
      N/A
    • Documentation in Release Notes:
      N/A
    • Similar issues:

      Description

      The problem seems to be related to the ajax locking mechanism that is performed in Administration. I`m not sure what exactly causes it, but I see it quite often and I was unable to reproduce it right now when I wanted to trigger it manually.

      Repetitively switching between Application sections or applying changes in some sections (like switching the search backend in the search application), seems to trigger the stacktrace. It could be a synchronization issue or something like that because, at first glance, it seems to be random.

      This is how the stacktrace looks like:

      2013-01-28 15:42:35,418 [http://localhost:8080/xwiki/bin/lock/XWiki/SearchAdmin?ajax=1] ERROR o.h.j.AbstractBatcher          - Exception executing batch:  
      org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
              at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:85) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:70) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.jdbc.BatchingBatcher.checkRowCounts(BatchingBatcher.java:90) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268) [hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:268) [hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:185) [hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) [hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51) [hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1216) [hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:383) [hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:133) [hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at com.xpn.xwiki.store.XWikiHibernateBaseStore.endTransaction(XWikiHibernateBaseStore.java:936) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.store.XWikiHibernateStore.saveLock(XWikiHibernateStore.java:1654) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.store.XWikiCacheStore.saveLock(XWikiCacheStore.java:522) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.doc.XWikiDocument.setLock(XWikiDocument.java:6113) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.web.LockAction.action(LockAction.java:48) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:230) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:116) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:431) [struts-1.2.9.jar:1.2.9]
              at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:236) [struts-1.2.9.jar:1.2.9]
              at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1196) [struts-1.2.9.jar:1.2.9]
              at org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:432) [struts-1.2.9.jar:1.2.9]
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:727) [servlet-api-2.5.jar:2.5]
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) [servlet-api-2.5.jar:2.5]
              at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1352) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at com.xpn.xwiki.web.ActionFilter.doFilter(ActionFilter.java:120) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.xwiki.wysiwyg.server.filter.ConversionFilter.doFilter(ConversionFilter.java:144) [xwiki-platform-wysiwyg-server-4.5-SNAPSHOT.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at com.xpn.xwiki.plugin.webdav.XWikiDavFilter.doFilter(XWikiDavFilter.java:66) [xwiki-platform-webdav-server-4.5-SNAPSHOT.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:208) [xwiki-platform-container-servlet-4.5-20130126.090556-101.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:111) [xwiki-platform-container-servlet-4.5-20130126.090556-101.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:476) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517) [jetty-security-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.Server.handle(Server.java:346) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1048) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:601) [jetty-http-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:214) [jetty-http-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535) [jetty-io-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40) [jetty-io-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529) [jetty-util-7.4.5.v20110725.jar:7.4.5.v20110725]
              at java.lang.Thread.run(Thread.java:722) [na:1.7.0_03]
      2013-01-28 15:42:35,420 [http://localhost:8080/xwiki/bin/lock/XWiki/SearchAdmin?ajax=1] WARN  c.x.x.w.XWikiAction            - Uncaught exception: Error number 13006 in 3: Exception while locking document
      Wrapped Exception: Failed to commit or rollback transaction. Root cause [] 
      com.xpn.xwiki.XWikiException: Error number 13006 in 3: Exception while locking document
      Wrapped Exception: Failed to commit or rollback transaction. Root cause []
              at com.xpn.xwiki.store.XWikiHibernateStore.saveLock(XWikiHibernateStore.java:1657) ~[xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.store.XWikiCacheStore.saveLock(XWikiCacheStore.java:522) ~[xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.doc.XWikiDocument.setLock(XWikiDocument.java:6113) ~[xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.web.LockAction.action(LockAction.java:48) ~[xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:230) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:116) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:431) [struts-1.2.9.jar:1.2.9]
              at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:236) [struts-1.2.9.jar:1.2.9]
              at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1196) [struts-1.2.9.jar:1.2.9]
              at org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:432) [struts-1.2.9.jar:1.2.9]
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:727) [servlet-api-2.5.jar:2.5]
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) [servlet-api-2.5.jar:2.5]
              at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:538) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1352) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at com.xpn.xwiki.web.ActionFilter.doFilter(ActionFilter.java:120) [xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.xwiki.wysiwyg.server.filter.ConversionFilter.doFilter(ConversionFilter.java:144) [xwiki-platform-wysiwyg-server-4.5-SNAPSHOT.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at com.xpn.xwiki.plugin.webdav.XWikiDavFilter.doFilter(XWikiDavFilter.java:66) [xwiki-platform-webdav-server-4.5-SNAPSHOT.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:208) [xwiki-platform-container-servlet-4.5-20130126.090556-101.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:111) [xwiki-platform-container-servlet-4.5-20130126.090556-101.jar:na]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1323) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:476) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:517) [jetty-security-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:937) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406) [jetty-servlet-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:871) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.Server.handle(Server.java:346) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:589) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1048) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:601) [jetty-http-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:214) [jetty-http-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:411) [jetty-server-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:535) [jetty-io-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40) [jetty-io-7.4.5.v20110725.jar:7.4.5.v20110725]
              at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529) [jetty-util-7.4.5.v20110725.jar:7.4.5.v20110725]
              at java.lang.Thread.run(Thread.java:722) [na:1.7.0_03]
      Caused by: org.hibernate.HibernateException: Failed to commit or rollback transaction. Root cause []
              at com.xpn.xwiki.store.XWikiHibernateBaseStore.endTransaction(XWikiHibernateBaseStore.java:943) ~[xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              at com.xpn.xwiki.store.XWikiHibernateStore.saveLock(XWikiHibernateStore.java:1654) ~[xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              ... 45 common frames omitted
      Caused by: org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
              at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:85) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:70) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.jdbc.BatchingBatcher.checkRowCounts(BatchingBatcher.java:90) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:268) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:185) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1216) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:383) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:133) ~[hibernate-core-3.6.9.Final.jar:3.6.9.Final]
              at com.xpn.xwiki.store.XWikiHibernateBaseStore.endTransaction(XWikiHibernateBaseStore.java:936) ~[xwiki-platform-legacy-oldcore-4.5-20130126.101925-99.jar:na]
              ... 46 common frames omitted
      

      Also, using the Firebug Console, I see a first extra unlock (cancel action) js call in each Applications section that does not look right. It always corresponds to the previous Application section visited, but I think it should happen in the previous request and not in the current one:

      POST http://localhost:8080/xwiki/bin/cancel/XWiki/WysiwygEditorConfig?ajax=1 204 No Content 182ms prototype.js (line 8)
      
      POST http://localhost:8080/xwiki/bin/lock/XWiki/MessageStreamConfig?ajax=1 204 No Content 195ms prototype.js (line 8)
      
      GET http://localhost:8080/xwiki/bin/lock/XWiki/XWikiPreferences?ajax=1&action=admin&language=en 204 No Content 93ms
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                mflorea Marius Dumitru Florea
                Reporter:
                enygma Eduard Moraru
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:
                  Date of First Response: