[Building Sakai] Add Particicpants MySQL table lock
Jon Higham
J.Higham at hull.ac.uk
Wed Feb 17 08:07:11 PST 2010
It's good to know that we are not alone in experiencing this.
I notice that rutgers' suggested mysql configurations (http://confluence.sakaiproject.org/display/PROD/Rutgers+performance+tuning+experience) use testOnBorrow at javax.sql.BaseDataSource=false & wait_timeout = 31536000
It looks like we use testOnBorrow at javax.sql.BaseDataSource=true & the default wait_timeout = 50
I don't know whether this is an issue, but I'll discuss this with our DB Admin when he returns next week.
Thanks
Jon
-----Original Message-----
From: sakai-dev-bounces at collab.sakaiproject.org [mailto:sakai-dev-bounces at collab.sakaiproject.org] On Behalf Of Jean-Francois Leveque
Sent: 17 February 2010 11:29
To: Jon Higham
Cc: Sakai-Dev
Subject: Re: [Building Sakai] Add Particicpants MySQL table lock
Without using the webservices, users have been experiencing the same
problem at UPMC.
We also get
java.sql.SQLException: Lock wait timeout exceeded; try restarting
transaction
but this happens within a org.quartz.JobPersistenceException.
Maybe the problem happens without the lock wait timeout.
Some of our users who weren't able to add participants were able to add
participants again after a logout/login.
Hope this helps.
I haven't checked the SAKAI_EVENT table yet but can.
Thanks
Jean-Francois
Jon Higham a écrit :
> We use addMemberToSiteWithRole & removeMemberFromSite webservices to
> add/remove users.
>
> The problem I have is reproducing the error. Adding and removing members
> on the same site works by the time it has been reported.
>
> I'll give the manual execution of the query a try.
>
>
> Thanks
>
> Jon
>
>
> -----Original Message-----
> From: sakai-dev-bounces at collab.sakaiproject.org
> [mailto:sakai-dev-bounces at collab.sakaiproject.org] On Behalf Of Stephen
> Marquard
> Sent: 16 February 2010 14:54
> To: Sakai-Dev; Jon Higham
> Subject: Re: [Building Sakai] Add Particicpants MySQL table lock
>
> Hi Jon,
>
> You should start by graphing some basic mysql metrics, including slow
> queries (and log them) and number of mysql connections.
>
> Then if you can reproduce this, the 'lock wait timeout' will take 50s,
> so during that time the operation will appear to hang in the browser,
> and if you run from a mysql prompt:
>
> show processlist;
> show innodb status;
>
> you should be able to see what other transaction has the table locked
> (probably SAKAI_REALM).
>
> There's an outside chance it could be caused by a missing index. Try
> executing a query such as the one referenced in the stack trace manually
> (from the mysql prompt) and see how long it takes.
>
> What "web services to add/remove site members" are you using?
>
> Regards
> Stephen
>
>>>> "Jon Higham" <J.Higham at hull.ac.uk> 2/16/2010 4:14 PM >>>
> The only customised code around site-manage is some to prevent
> Instructors from deleting their own sites and hiding of the site contact
> details, so I don't think that is the issue.
>
> I will check DB load with our DB admin, who is on leave this week, but
> would be surprised if he hadn't mentioned high load.
>
> My first thoughts were that it was linked to there being a large number
> of users on the site (approx 580), but we can experience the problem on
> small member sizes (12) and when adding or removing members
> individually.
>
> I have also noticed that the Instructors adding users sometimes have 2
> sessions open, and perhaps trying to update membership simultaneously on
> both, but again that doesn't appear to be the case.
>
> I've also wondered it could be linked to us using web services to
> add/remove site members somehow interfering, but again I don't see why
> that would happen.
>
> Could missing something on a conversion script cause the issue?
>
>
> Jon
>
>
> -----Original Message-----
> From: sakai-dev-bounces at collab.sakaiproject.org
> [mailto:sakai-dev-bounces at collab.sakaiproject.org] On Behalf Of Stephen
> Marquard
> Sent: 16 February 2010 12:10
> To: Sakai-Dev; Jon Higham
> Subject: Re: [Building Sakai] Add Particicpants MySQL table lock
>
> Lock wait timeouts are very unusual - it basically means other queries
> have locked one or more of the tables involved for update for greater
> than 50 seconds (unless your mysql settings for this are non-standard).
>
> Is your MySQL server under extreme load, or do you have any other custom
> code or processes that is perhaps using these tables and not handling
> locking correctly?
>
> Regards
> Stephen
>
>>>> "Jon Higham" <J.Higham at hull.ac.uk> 2010/02/16 02:03 PM >>>
> We are running sakai 2.6 with MySQL. Occasionally, site instructors
> report that they have gone through the procedure (Site Info > Add
> Participants) to manually add users to their sites. No errors or
> warnings are given to the Instructor, but the users are not added. This
> also occasionally occurs for removing users too.
>
>
>
> Looking at the sakai_event table I can see a row showing
> site.upd.site.mbrshp, but this is not followed by site.upd. Later
> attempts, that eventually work for the Instructor, show a
> site.upd.site.mbrshp row followed by site.upd.
>
>
>
> The logs for this happening are below. Looks like a lock on the table
> causing a timeout. Can anyone suggest what might be causing the lock?
>
>
>
> Thanks
>
>
>
> Jon Higham
>
> IT Systems
>
> University of Hull
>
>
>
>
>
> 2010-02-14 08:50:14,888 [TP-Processor551] WARN
> org.sakaiproject.db.impl.BasicSqlService - Sql.dbWrite(): error code:
> 1205 sql: update SAKAI_REALM set PROVIDER_ID = ?,MAINTAIN_ROLE = (select
> MAX(ROLE_KEY) from SAKAI_REALM_ROLE where ROLE_NAME = ?),CREATEDBY =
> ?,MODIFIEDBY = ?,CREATEDON = ?,MODIFIEDON = ? where ( REALM_ID = ? )
> binds: Instructor admin ggshf 20081217141209000 20100214084923732
> /site/20239_0910S2
>
> java.sql.SQLException: Lock wait timeout exceeded; try restarting
> transaction
>
> at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1055)
>
> at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
>
> at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3515)
>
> at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3447)
>
> at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1951)
>
> at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2101)
>
> at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2554)
>
> at
> com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:
> 1761)
>
> at
> com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:20
> 46)
>
> at
> com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:19
> 64)
>
> at
> com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:19
> 49)
>
> at
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(Delega
> tingPreparedStatement.java:102)
>
> at
> org.sakaiproject.db.impl.BasicSqlService.dbWrite(BasicSqlService.java:12
> 05)
>
> at
> org.sakaiproject.db.impl.BasicSqlService.dbWrite(BasicSqlService.java:10
> 39)
>
> at
> org.sakaiproject.util.BaseDbFlatStorage.commitResource(BaseDbFlatStorage
> .java:855)
>
> at
> org.sakaiproject.authz.impl.DbAuthzGroupService$DbStorage.saveTx(DbAuthz
> GroupService.java:1015)
>
> at
> org.sakaiproject.authz.impl.DbAuthzGroupService$DbStorage$8.run(DbAuthzG
> roupService.java:986)
>
> at
> org.sakaiproject.db.impl.BasicSqlService.transact(BasicSqlService.java:3
> 28)
>
> at
> org.sakaiproject.authz.impl.DbAuthzGroupService$DbStorage.save(DbAuthzGr
> oupService.java:982)
>
> at
> org.sakaiproject.authz.impl.BaseAuthzGroupService.completeSave(BaseAuthz
> GroupService.java:592)
>
> at
> org.sakaiproject.authz.impl.BaseAuthzGroupService.save(BaseAuthzGroupSer
> vice.java:578)
>
> at
> org.sakaiproject.site.tool.helper.participant.impl.SiteAddParticipantHan
> dler.addUsersRealm(SiteAddParticipantHandler.java:503)
>
> at
> org.sakaiproject.site.tool.helper.participant.impl.SiteAddParticipantHan
> dler.processConfirmContinue(SiteAddParticipantHandler.java:591)
>
> at sun.reflect.GeneratedMethodAccessor11940.invoke(Unknown Source)
>
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessor
> Impl.java:25)
>
> at java.lang.reflect.Method.invoke(Method.java:585)
>
> at
> uk.org.ponder.reflect.JDKReflectiveCache.invokeMethod(JDKReflectiveCache
> .java:23)
>
> at
> uk.org.ponder.reflect.JDKReflectiveCache.invokeMethod(JDKReflectiveCache
> .java:17)
>
> at
> uk.org.ponder.reflect.JDKReflectiveCache.invokeMethod(JDKReflectiveCache
> .java:77)
>
> at
> uk.org.ponder.reflect.ReflectiveCache.invokeMethod(ReflectiveCache.java:
> 141)
>
> at
> uk.org.ponder.mapping.support.DARApplier.invokeBeanMethod(DARApplier.jav
> a:179)
>
> at
> uk.org.ponder.rsf.state.support.RSVCApplier.invokeAction(RSVCApplier.jav
> a:218)
>
> at
> uk.org.ponder.rsf.processor.support.RSFActionHandler$1.run(RSFActionHand
> ler.java:189)
>
> at
> uk.org.ponder.util.CollectingRunnableInvoker$1.run(CollectingRunnableInv
> oker.java:25)
>
> at
> uk.org.ponder.rsf.flow.support.BasicScopedAlterationWrapper.lockUUPP(Bas
> icScopedAlterationWrapper.java:73)
>
> at
> uk.org.ponder.rsf.flow.support.BasicScopedAlterationWrapper.lockUUPP(Bas
> icScopedAlterationWrapper.java:80)
>
> at
> uk.org.ponder.rsf.flow.support.BasicScopedAlterationWrapper.invokeRunnab
> le(BasicScopedAlterationWrapper.java:64)
>
> at
> uk.org.ponder.rsf.flow.support.BasicScopedAlterationWrapper$$FastClassBy
> CGLIB$$84f89202.invoke(<generated>)
>
> at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
>
> at
> org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedIntercept
> or.intercept(Cglib2AopProxy.java:623)
>
> at
> uk.org.ponder.rsf.flow.support.BasicScopedAlterationWrapper$$EnhancerByC
> GLIB$$9392038c.invokeRunnable(<generated>)
>
> at
> uk.org.ponder.rsf.flow.support.BasicScopedAlterationWrapper$$FastClassBy
> CGLIB$$84f89202.invoke(<generated>)
>
> at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
>
> at
> org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedIntercept
> or.intercept(Cglib2AopProxy.java:623)
>
> at
> uk.org.ponder.rsf.flow.support.BasicScopedAlterationWrapper$$EnhancerByC
> GLIB$$9392038c.invokeRunnable(<generated>)
>
> at
> uk.org.ponder.util.CollectingRunnableInvoker$1.run(CollectingRunnableInv
> oker.java:29)
>
> at
> uk.org.ponder.util.CollectingRunnableInvoker.invokeWrappers(CollectingRu
> nnableInvoker.java:22)
>
> at
> uk.org.ponder.util.CollectingRunnableInvoker.invokeRunnable(CollectingRu
> nnableInvoker.java:14)
>
> at
> uk.org.ponder.rsf.processor.support.RSFActionHandler.handle(RSFActionHan
> dler.java:165)
>
> at
> uk.org.ponder.rsf.processor.support.RSFActionHandler$$FastClassByCGLIB$$
> e3b6899d.invoke(<generated>)
>
> at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
>
> at
> org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedIntercept
> or.intercept(Cglib2AopProxy.java:623)
>
> at
> uk.org.ponder.rsf.processor.support.RSFActionHandler$$EnhancerByCGLIB$$6
> 3cbf9f5.handle(<generated>)
>
> at
> uk.org.ponder.rsf.processor.support.RootHandlerBeanBase.handlePost(RootH
> andlerBeanBase.java:125)
>
> at
> uk.org.ponder.rsf.processor.support.RootHandlerBeanBase.handle(RootHandl
> erBeanBase.java:82)
>
> at sun.reflect.GeneratedMethodAccessor5806.invoke(Unknown Source)
>
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessor
> Impl.java:25)
>
> at java.lang.reflect.Method.invoke(Method.java:585)
>
> at
> uk.org.ponder.reflect.JDKReflectiveCache.invokeMethod(JDKReflectiveCache
> .java:23)
>
> at
> uk.org.ponder.reflect.JDKReflectiveCache.invokeMethod(JDKReflectiveCache
> .java:17)
>
> at
> uk.org.ponder.reflect.JDKReflectiveCache.invokeMethod(JDKReflectiveCache
> .java:77)
>
> at
> uk.org.ponder.rsac.support.RSACBeanLocatorImpl.createBean(RSACBeanLocato
> rImpl.java:553)
>
> at
> uk.org.ponder.rsac.support.RSACBeanLocatorImpl.access$000(RSACBeanLocato
> rImpl.java:75)
>
> at
> uk.org.ponder.rsac.support.RSACBeanLocatorImpl$1.run(RSACBeanLocatorImpl
> .java:449)
>
> at
> uk.org.ponder.rsac.RSACErrorBridge.invokeRunnable(RSACErrorBridge.java:3
> 8)
>
> at
> uk.org.ponder.rsac.support.RSACBeanLocatorImpl.createBean(RSACBeanLocato
> rImpl.java:447)
>
> at
> uk.org.ponder.rsac.support.RSACBeanLocatorImpl.getLocalBean(RSACBeanLoca
> torImpl.java:348)
>
> at
> uk.org.ponder.rsac.support.RSACBeanLocatorImpl.getBean(RSACBeanLocatorIm
> pl.java:379)
>
> at
> uk.org.ponder.rsac.support.PerRequestInfo$1.locateBean(PerRequestInfo.ja
> va:49)
>
> at
> uk.ac.cam.caret.sakai.rsf.servlet.ReasonableSakaiServlet.service(Reasona
> bleSakaiServlet.java:65)
>
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applica
> tionFilterChain.java:269)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilt
> erChain.java:188)
>
> at
> org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatc
> her.java:679)
>
> at
> org.apache.catalina.core.ApplicationDispatcher.processRequest(Applicatio
> nDispatcher.java:461)
>
> at
> org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDisp
> atcher.java:364)
>
> at
> org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispat
> cher.java:301)
>
> at
> org.sakaiproject.tool.impl.ActiveToolComponent$MyActiveTool.help(ActiveT
> oolComponent.java:545)
>
> at
> org.sakaiproject.cheftool.ToolServlet.sendToHelper(ToolServlet.java:652)
>
> at
> org.sakaiproject.cheftool.ToolServlet.doGet(ToolServlet.java:212)
>
> at
> org.sakaiproject.cheftool.VelocityPortletPaneledAction.doGet(VelocityPor
> tletPaneledAction.java:1014)
>
> at
> org.sakaiproject.cheftool.ToolServlet.doPost(ToolServlet.java:151)
>
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
>
> at
> org.sakaiproject.vm.ComponentServlet.service(ComponentServlet.java:56)
>
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applica
> tionFilterChain.java:269)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilt
> erChain.java:188)
>
> at
> org.sakaiproject.util.RequestFilter.doFilter(RequestFilter.java:565)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applica
> tionFilterChain.java:215)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilt
> erChain.java:188)
>
> at
> org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatc
> her.java:679)
>
> at
> org.apache.catalina.core.ApplicationDispatcher.processRequest(Applicatio
> nDispatcher.java:461)
>
> at
> org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDisp
> atcher.java:364)
>
> at
> org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispat
> cher.java:301)
>
> at
> org.sakaiproject.tool.impl.ActiveToolComponent$MyActiveTool.forward(Acti
> veToolComponent.java:475)
>
> at
> org.sakaiproject.portal.charon.SkinnableCharonPortal.forwardTool(Skinnab
> leCharonPortal.java:1216)
>
> at
> org.sakaiproject.portal.charon.handlers.ToolHandler.doTool(ToolHandler.j
> ava:188)
>
> at
> org.sakaiproject.portal.charon.handlers.ToolHandler.doGet(ToolHandler.ja
> va:93)
>
> at
> org.sakaiproject.portal.charon.handlers.ToolHandler.doPost(ToolHandler.j
> ava:70)
>
> at
> org.sakaiproject.portal.charon.SkinnableCharonPortal.doPost(SkinnableCha
> ronPortal.java:1059)
>
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
>
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applica
> tionFilterChain.java:269)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilt
> erChain.java:188)
>
> at
> org.sakaiproject.util.RequestFilter.doFilter(RequestFilter.java:616)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applica
> tionFilterChain.java:215)
>
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilt
> erChain.java:188)
>
> at
> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValv
> e.java:213)
>
> at
> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValv
> e.java:174)
>
> at
> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java
> :127)
>
> at
> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java
> :117)
>
> at
> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.
> java:108)
>
> at
> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:1
> 74)
>
> at
> org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:200)
>
> at
> org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:283)
>
> at
> org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:773)
>
> at
> org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:
> 703)
>
> at
> org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.
> java:895)
>
> at
> org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool
> .java:689)
>
> at java.lang.Thread.run(Thread.java:595)
>
> 2010-02-14 08:50:14,911 [TP-Processor551] WARN
> org.sakaiproject.db.impl.BasicSqlService - transact: rolling back:
> azg:/site/20239_0910S2
>
> 2010-02-14 08:50:14,911 [TP-Processor551] WARN
> org.sakaiproject.db.impl.BasicSqlService - transact: failure:
> java.lang.RuntimeException: SqlService.dbWrite failure
>
> 2010-02-14 08:50:14,912 [TP-Processor551] WARN
> org.sakaiproject.site.tool.helper.participant.impl.SiteAddParticipantHan
> dler -
> org.sakaiproject.site.tool.helper.participant.impl.SiteAddParticipantHan
> dler at 507d337b.addUsersRealm: SqlService.dbWrite failure
> realmId=/site/20239_0910S2
>
> 2010-02-14 08:50:14,912 [TP-Processor551] INFO PonderUtilCore -
> BeanCopy preserved to path siteAddParticipantHandler:
> org.sakaiproject.site.tool.helper.participant.impl.SiteAddParticipantHan
> dler at 507d337b
>
> 2010-02-14 08:50:14,913 [TP-Processor551] INFO PonderUtilCore -
> BeanCopy saved 1 beans to token resultScope
>
> 2010-02-14 08:50:14,913 [TP-Processor551] INFO PonderUtilCore -
> Redirecting to
> /portal/tool/849b094d-629c-474b-00ca-3acb5766d961?sakai.tool.helper.idMa
> in=done&panel=Main
_______________________________________________
sakai-dev mailing list
sakai-dev at collab.sakaiproject.org
http://collab.sakaiproject.org/mailman/listinfo/sakai-dev
TO UNSUBSCRIBE: send email to sakai-dev-unsubscribe at collab.sakaiproject.org with a subject of "unsubscribe"
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: not available
Url: http://collab.sakaiproject.org/pipermail/sakai-dev/attachments/20100217/6a6d8aa4/attachment.pl
More information about the sakai-dev
mailing list