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)

    XMLWordPrintable

Details

    • Medium
    • N/A
    • N/A

    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

          is related to

          Bug - A problem which impairs or prevents the functions of the product. XWIKI-8735 Locked Logging administration panel with useless "force edit" link

          • Major - Major loss of function.
          • Closed

          Activity

            People

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

              Dates

                Created:
                Updated:
                Resolved: