[Deploying Sakai] [Building Sakai] Sakai 2.9 performance issue
Sanghyun Jeon
euksa99 at gmail.com
Mon Mar 24 11:08:03 PDT 2014
I increased the memory from 8GB to 16 GB per each server but I have the
similar issue. So I don't think our tomcats are running out of memory. More
than 9G memory is left. Almost more than 90% CPU is idle. I attached thread
dump when our tomcat do not do anything at all and looks like waiting
something.
And below is the tomcat log at the same time.There is more than 30 minutes
waiting for something. it is worth mentioning we have two app servers and
each server has two tomcats running. Looks like the second running server
is always suffering for some starvation. Two tomcats of the first server
take about 4 minutes to be up while two tomcats of the second server take
more than 30 minutes to be up. I think Clustering set up or some race
condition might be problem but I really could not pinpoint it based on
thread dump and tomcat log. Thread dump shows two BLOCKED
("org.sakaiproject.event.impl.ClusterEventTracking$$EnhancerByCGLIB$$33ba687"
and "Sakai.SessionComponent.Maintenance") and can anybody tell me whether I
need to worry about them or not? Thank you
2014-03-22 15:05:47.605 [INFO]
org.sakaiproject.springframework.orm.hibernate.AddableSessionFactoryBean:950
- Updating database schema for Hibernate SessionFactory
2014-03-22 15:05:53.721 [INFO]
org.sakaiproject.id.impl.UuidV4IdComponent:53 - init()
2014-03-22 15:05:53.823 [INFO]
org.sakaiproject.entity.impl.EntityManagerComponent:184 - init()
2014-03-22 15:05:53.830 [INFO]
org.sakaiproject.authz.impl.FunctionManagerComponent:63 - init()
2014-03-22 15:12:40.732 [INFO]
org.sakaiproject.event.impl.BaseEventTrackingService:173 -
org.sakaiproject.event.impl.ClusterEventTracking$$EnhancerByCGLIB$$33ba687 at 4a2cf238.init
()
2014-03-22 15:12:40.747 [INFO]
org.sakaiproject.event.impl.ClusterEventTracking:235 -
org.sakaiproject.event.impl.ClusterEventTracking$$EnhancerByCGLIB$$33ba687 at 4a2cf238.init()
- period: 5 batch: true checkDb: true
2014-03-22 15:12:40.778 [INFO] org.sakaiproject.tool.impl.ToolComponent:224
- init(): hidden tools: sakai.mailtool sakai.bbb sakai.melete
sakai.search sakai.presentation sakai.su blogger sakai.rsf.evaluation
sakai.kaltura sakai.profile sakai.rutgers.linktool sakai.reports
sakai.timeline sakai.basiclti.admin sakai.basiclti.admin.helper
2014-03-22 15:12:41.013 [INFO] org.sakaiproject.site.impl.DbSiteService:176
- init(): site table: SAKAI_SITE external locks: true
2014-03-22 15:12:41.191 [INFO]
org.sakaiproject.coursemanagement.impl.CourseManagementServiceHibernateImpl:64
- Initializing
org.sakaiproject.coursemanagement.impl.CourseManagementServiceHibernateImpl
2014-03-22 15:12:41.256 [INFO]
org.sakaiproject.coursemanagement.impl.provider.CourseManagementGroupProvider:212
- initializing
org.sakaiproject.coursemanagement.impl.provider.CourseManagementGroupProvider
2014-03-22 15:12:41.263 [INFO]
org.sakaiproject.authz.impl.BaseAuthzGroupService:291 - init(): provider:
com.sun.proxy.$Proxy10
2014-03-22 15:12:41.274 [INFO]
org.sakaiproject.authz.impl.DbAuthzGroupService:232 - init(): table:
SAKAI_REALM external locks: true
2014-03-22 15:13:05.228 [INFO]
org.sakaiproject.event.impl.UsageSessionServiceAdaptor:226 - init()
2014-03-22 15:13:05.270 [INFO] org.sakaiproject.time.api.TimeService:128 -
init()
2014-03-22 15:13:05.275 [INFO]
org.sakaiproject.memory.impl.BasicMemoryService:140 - init()
2014-03-22 15:13:05.279 [INFO]
org.sakaiproject.memory.impl.BasicMemoryService:167 - Added Cache name
[org.sakaiproject.user.impl.BasePreferencesService.preferences] as Cache
[org.sakaiproject.user.impl.BasePreferencesService.preferences]
2014-03-22 15:13:05.279 [INFO]
org.sakaiproject.user.impl.BasePreferencesService:258 - init()
2014-03-22 15:13:05.280 [INFO]
org.sakaiproject.user.impl.DbPreferencesService:116 - init(): table:
SAKAI_PREFERENCES locks-in-db: false
EntityProviderManagerImpl init
INFO Registered entity provider
(org.sakaiproject.entitybroker.impl.entityprovider.EntityProviderManagerImpl$1)
prefix (describe) with 1 capabilities
2014-03-22 15:13:05.419 [INFO]
org.sakaiproject.email.impl.BasicEmailService:397 - init(): smtp:
sakaitest.aiso.claremont.edu bounces to:
postmaster at Sakaitest.AISO.Claremont.Edu maxRecipients: 100 testMode: false
INFO: [GenericDao] Could not execute first DDL line, skipping the rest:
StatementCallback; bad SQL grammar [CREATE TABLE ENTITY_PROPERTIES (
id bigint(20) AUTO_INCREMENT NOT NULL PRIMARY KEY,
entityRef varchar(255) NOT NULL, entityPrefix varchar(255) NOT
NULL, propertyName varchar(255) NOT NULL, propertyValue text NOT NULL,
INDEX (entityRef, entityPrefix, propertyName) )]; nested exception is
com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table
'ENTITY_PROPERTIES' already
exists:com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table
'ENTITY_PROPERTIES' already exists
INFO: [GenericDao] Could not execute first DDL line, skipping the rest:
StatementCallback; bad SQL grammar [CREATE TABLE ENTITY_TAG_APPLICATIONS (
id bigint(20) AUTO_INCREMENT NOT NULL PRIMARY KEY,
entityRef varchar(255) NOT NULL, entityPrefix varchar(255) NOT
NULL, tag varchar(255) NOT NULL, INDEX (entityRef,
entityPrefix, tag) )]; nested exception is
com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table
'ENTITY_TAG_APPLICATIONS' already
exists:com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table
'ENTITY_TAG_APPLICATIONS' already exists
2014-03-22 15:37:19.000 [INFO]
org.sakaiproject.memory.impl.BasicMemoryService:167 - Added Cache name
[org.sakaiproject.user.api.UserDirectoryService.callCache] as Cache
[org.sakaiproject.user.api.UserDirectoryService.callCache]
2014-03-22 15:37:19.050 [INFO]
org.sakaiproject.user.impl.BaseUserDirectoryService:577 - init(): provider:
edu.amc.sakai.user.HMCJLDAPDirectoryProvider separateIdEid: true
2014-03-22 15:37:19.051 [INFO] org.sakaiproject.user.impl.DbUserService:188
- init(): table: SAKAI_USER external locks: true
2014-03-22 15:37:19.051 [INFO] org.sakaiproject.user.impl.DbUserService:190
- Cache [org.sakaiproject.user.api.UserDirectoryService] Memory Store
Eviction Policy [net.sf.ehcache.store.LruPolicy at 75c6232a]
2014-03-22 15:37:19.052 [DEBUG]
org.sakaiproject.user.impl.PrecachingDbUserService:94 - init():
(grand-super) BaseUserDirectoryService includes this general cache just
created in its code,
m_callCache==org.sakaiproject.memory.impl.MemCache at 232ed6ce
2014-03-22 15:37:19.052 [DEBUG]
org.sakaiproject.user.impl.PrecachingDbUserService:95 - init(): (super)
DbUserService includes this eid/id map, wired in user-components.xml,
cache==[ name = org.sakaiproject.user.api.UserDirectoryService status =
STATUS_ALIVE eternal = false overflowToDisk = false maxEntriesLocalHeap =
100000 maxEntriesLocalDisk = 0 memoryStoreEvictionPolicy = LRU
timeToLiveSeconds = 7200 timeToIdleSeconds = 7200 diskPersistent = false
diskExpiryThreadIntervalSeconds = 120 cacheEventListeners:
net.sf.ehcache.statistics.LiveCacheStatisticsWrapper hitCount = 0
memoryStoreHitCount = 0 diskStoreHitCount = 0 missCountNotFound = 0
missCountExpired = 0 maxBytesLocalHeap = 0 overflowToOffHeap = false
maxBytesLocalOffHeap = 0 maxBytesLocalDisk = 0 pinned = false ]
2014-03-22 15:37:19.053 [INFO]
org.sakaiproject.user.impl.PrecachingDbUserService:121 - User precache not
scheduled for startup run
2014-03-22 15:37:19.054 [INFO]
org.sakaiproject.user.impl.PrecachingDbUserService:149 - User precache not
scheduled for daily run
2014-03-22 15:37:19.056 [INFO]
org.sakaiproject.accountvalidator.logic.impl.ValidationLogicImpl:95 - init()
2014-03-22 15:37:19.564 [INFO]
org.sakaiproject.memory.impl.BasicMemoryService:167 - Added Cache name
[org.sakaiproject.alias.api.AliasService.callCache] as Cache
[org.sakaiproject.alias.api.AliasService.callCache]
2014-03-22 15:37:19.565 [INFO]
org.sakaiproject.alias.impl.DbAliasService:158 - init(): table: SAKAI_ALIAS
external locks: true checkOld: false
2014-03-22 15:37:19.585 [INFO]
org.sakaiproject.event.impl.BaseNotificationService:219 -
org.sakaiproject.event.impl.DbNotificationService$$EnhancerByCGLIB$$c2de2624 at 13950335.init()
started
2014-03-22 15:37:19.591 [INFO]
org.sakaiproject.memory.impl.BasicMemoryService:167 - Added Cache name
[org.sakaiproject.event.api.NotificationService.cache] as Cache
[org.sakaiproject.event.api.NotificationService.cache]
2014-03-22 15:37:19.592 [INFO]
org.sakaiproject.event.impl.BaseNotificationService:235 -
org.sakaiproject.event.impl.DbNotificationService$$EnhancerByCGLIB$$c2de2624 at 13950335.init()
complete
2014-03-22 15:37:19.593 [INFO]
org.sakaiproject.event.impl.DbNotificationService:120 - .init(): table:
SAKAI_NOTIFICATION locks-in-db: false
2014-03-22 15:37:19.623 [INFO]
org.sakaiproject.content.impl.DbResourceTypeRegistry:234 - init()
2014-03-22 15:37:19.626 [INFO]
org.sakaiproject.content.impl.ResourceTypeRegistryImpl:78 - init()
2014-03-22 15:37:19.633 [INFO]
org.sakaiproject.antivirus.impl.ClamAVScanner:92 - init()
2014-03-22 15:37:19.756 [INFO]
org.sakaiproject.content.impl.DbContentService:421 - Migration of data to
the Binary format will be performed by this node
2014-03-22 15:37:19.808 [INFO]
org.sakaiproject.content.impl.BaseContentService:769 - Loaded Storage as
org.sakaiproject.content.impl.DbContentService$DbStorage at 7618b073 for
org.sakaiproject.content.impl.DbContentService at 4ee88a97
2014-03-22 15:37:19.823 [INFO]
org.sakaiproject.content.impl.BaseContentService:840 - init(): site quota:
2097152, dropbox quota: 1048576, body path: /opt/sakai-data volumes: body,
2014-03-22 15:37:19.823 [INFO]
org.sakaiproject.content.impl.DbContentService:442 - init(): tables:
CONTENT_COLLECTION CONTENT_RESOURCE CONTENT_RESOURCE_BODY_BINARY
CONTENT_ENTITY_GROUPS locks-in-db: false bodyPath: /opt/sakai-data storage:
org.sakaiproject.content.impl.DbContentService$DbStorage at 7618b073
2014-03-22 15:37:19.831 [INFO]
org.sakaiproject.archive.impl.ArchiveService2Impl:110 - init(): storage
path: /opt/sakai-cfg/tc2A//archive/, merge filter{services=true, roles=true}
2014-03-22 15:37:19.852 [INFO]
org.sakaiproject.basiclti.impl.BasicLTISecurityServiceImpl:143 -
org.sakaiproject.basiclti.impl.BasicLTISecurityServiceImpl at 45dd82f0.init()
2014-03-22 15:37:19.852 [WARN]
org.sakaiproject.basiclti.impl.BasicLTISecurityServiceImpl:146 - BasicLTI
secrets in database unencrypted, please set basiclti.encryption.key
2014-03-22 15:37:19.883 [INFO] org.sakaiproject.lti.impl.BaseLTIService:160
- init()
2014-03-22 15:37:19.892 [WARN] org.sakaiproject.lti.impl.BaseLTIService:176
- launch=Missing LTIService Translation
2014-03-22 15:37:19.892 [WARN] org.sakaiproject.lti.impl.BaseLTIService:176
- consumerkey=Missing LTIService Translation
2014-03-22 15:37:19.892 [WARN] org.sakaiproject.lti.impl.BaseLTIService:176
- secret=Missing LTIService Translation
2014-03-22 15:37:19.959 [INFO]
org.sakaiproject.component.app.scheduler.ScheduledInvocationManagerImpl:65
- init()
2014-03-22 15:37:20.008 [INFO]
org.sakaiproject.event.impl.BaseEventTrackingService:190 - Setting the
event delay handler to
org.sakaiproject.content.providers.BaseEventDelayHandler at 515fa5da [was:
null]At f
On Sat, Mar 22, 2014 at 12:45 PM, Sam Ottenhoff <ottenhoff at longsight.com>wrote:
> There is no magic fix for an unresponsive Tomcat. You need to debug the
> issue to try to find the root of the issue. The most common problem is
> Tomcat running out of memory. To better understand what is in the JVM's
> memory, you need to get a heap dump of the unresponsive Tomcat instance and
> to analyze that heap dump in a tool like Eclipse MAT. MAT will provide you
> visual reports and lists of memory "dominators" that will most likely point
> to a specific problem. Once you have narrowed down where the problem is,
> members of this list can most likely help with possible fixes or
> suggestions where to look next.
>
>
> On Sat, Mar 22, 2014 at 11:39 AM, Sanghyun Jeon <euksa99 at gmail.com> wrote:
>
>> Hello all
>> We plan to upgrade sakai2.9.3 this summer and I think I have a similar
>> problem: unresponsive tomcats
>> We have tomcat 7.0.42 and java 1.7.0_40
>> JVM setting is below.
>> JAVA_OPTS="-server -d64 -Xmx6g -XX:MaxPermSize=512m
>> -Dorg.apache.jasper.compiler.Parser.STRICT_QUOTE_ESCAPING=false
>> -Djava.awt.headless=true -Dcom.sun.management.jmxremote
>> -Dsun.lang.ClassLoader.allowArraySyntax=true -Dhttp.agent=Sakai
>> -Dsakai.security=/opt/sakai-cfg -Dsakai.home=/opt/sakai-cfg/tc2A"
>>
>> I am wondering David found the root cause of this symptom and its
>> solution can be shared.
>> Thank you.
>>
>> S
>>
>>
>>
>> On Tue, May 28, 2013 at 5:49 AM, David Horwitz <david.horwitz at uct.ac.za>wrote:
>>
>>> Hi David,
>>>
>>>
>>> On Tue, 2013-05-28 at 08:15 -0400, David Haines wrote:
>>>
>>> David,
>>>
>>>
>>>
>>> At Michigan we've found that examining a heap dump usually makes
>>> the memory problem clear. YourKit does this well.
>>>
>>>
>>>
>>> Unfortunately my attempt to grab a production heap dump failed :( I got
>>> an error jdk error - we have upgraded to the latest 1.6 jdk and I will try
>>> get one if we see the issue resurface.
>>>
>>>
>>>
>>>
>>>
>>> If you reset all the caches from the memory tool does performance
>>> get better? That's not a long term solution but can help diagnose (and
>>> just might provide a short term bandaid).
>>>
>>>
>>>
>>> We only thought of that one after the fact - again something we will
>>> try if we can reproduce.
>>>
>>>
>>> D
>>>
>>>
>>> - Dave
>>>
>>>
>>>
>>> On Mon, May 27, 2013 at 9:24 AM, Aaron Zeckoski <azeckoski at unicon.net>
>>> wrote:
>>>
>>> I suggest you try changing one of your nodes JVM settings and drop the
>>> following from it.
>>>
>>> -Xms5000m -Xmx5000m -XX:+UseConcMarkSweepGC
>>>
>>> -XX:+ExplicitGCInvokesConcurrent -XX:+CMSIncrementalMode -verbose:gc
>>> -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDetails
>>> -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps
>>>
>>> -Dsun.lang.ClassLoader.allowArraySyntax=true
>>>
>>> Putting those in severely limits the JVM autotuning (also known as
>>> ergonomics).
>>> http://www.oracle.com/technetwork/java/javase/gc-tuning-6-140523.html
>>> (plus the slowdown from all the GC monitoring)
>>> Also, "-Dsun.lang.ClassLoader.allowArraySyntax=true" is no longer needed.
>>>
>>> Then monitor the node using jstat or something similar and compare it
>>> to the performance of the other nodes. You can tweak things from there
>>> but in most cases you will find the tuner handles things better on its
>>> own.
>>> -AZ
>>>
>>>
>>>
>>> On Mon, May 27, 2013 at 8:58 AM, David Horwitz <david.horwitz at uct.ac.za>
>>> wrote:
>>> > Hi All,
>>> >
>>> > We are/did experience a performance issue last week we would like to
>>> seek
>>> > community input on.
>>> >
>>> > Some back ground:
>>> >
>>> > Kernel 1,3,x based (1.3.2 msub with KNL-1068 applied)
>>> > Java 1.6.0_30
>>> > mysql 5.1.68
>>> >
>>> > Javaopts:
>>> >
>>> > -server -d64 -Xms5000m -Xmx5000m -XX:MaxPermSize=640m
>>> > -Dhttp.proxyHost=campusnet.uct.ac.za -Dhttp.proxyPort=8080
>>> > -XX:+UseConcMarkSweepGC -XX:+ExplicitGCInvokesConcurrent
>>> > -XX:+CMSIncrementalMode -verbose:gc -XX:+PrintGCApplicationStoppedTime
>>> > -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps
>>> > -Duser.language=en -Duser.region=ZA -Djava.awt.headless=true
>>> > -Dnetworkaddress.cache.ttl=60
>>> > -Dorg.apache.jasper.compiler.Parser.STRICT_QUOTE_ESCAPING=false
>>> > -Dsun.lang.ClassLoader.allowArraySyntax=true -Dhttp.agent=Sakai
>>> > -Djava.net.preferIPv6Addresses=false -Djava.net.preferIPv4Stack=true
>>> >
>>> >
>>> > Symptoms:
>>> > Randomly nodes enter a state where they become increasingly
>>> unresponsive due
>>> > to longer and more frequent full GC operations. Until Friday we seemed
>>> to
>>> > see this randomly with a higher incidence after the end of the
>>> lectures,
>>> > during extensive online testing on Friday we experienced this across
>>> all
>>> > nodes. It seems to be unrelated to the node running times as we have
>>> seen it
>>> > on nodes that have been restarted in the last 24 hours as well as
>>> others
>>> > that have been running for some time.
>>> >
>>> > Any one seen similar issues? As a preventative we have upgraded to the
>>> > latest 1.6 jdk (1.6.0_45) but are far from convinced this is the
>>> problem.
>>> >
>>> >
>>> > Thanks
>>> >
>>> > David
>>> > ________________________________
>>> > UNIVERSITY OF CAPE TOWN
>>> >
>>> > This e-mail is subject to the UCT ICT policies and e-mail disclaimer
>>> > published on our website at
>>> > http://www.uct.ac.za/about/policies/emaildisclaimer/ or obtainable
>>> from +27
>>> > 21 650 9111. This e-mail is intended only for the person(s) to whom it
>>> is
>>> > addressed. If the e-mail has reached you in error, please notify the
>>> author.
>>> > If you are not the intended recipient of the e-mail you may not use,
>>> > disclose, copy, redirect or print the content. If this e-mail is not
>>> related
>>> > to the business of UCT it is sent by the sender in the sender's
>>> individual
>>> > capacity.
>>> >
>>> >
>>>
>>> > _______________________________________________
>>> > production mailing list
>>> > production at collab.sakaiproject.org
>>> > http://collab.sakaiproject.org/mailman/listinfo/production
>>> >
>>> > TO UNSUBSCRIBE: send email to
>>> production-unsubscribe at collab.sakaiproject.org
>>> > with a subject of "unsubscribe"
>>>
>>>
>>>
>>> --
>>> Aaron Zeckoski - Software Architect - http://tinyurl.com/azprofile
>>> _______________________________________________
>>> production mailing list
>>> production at collab.sakaiproject.org
>>> http://collab.sakaiproject.org/mailman/listinfo/production
>>>
>>> TO UNSUBSCRIBE: send email to
>>> production-unsubscribe at collab.sakaiproject.org with a subject of
>>> "unsubscribe"
>>>
>>>
>>>
>>>
>>> ------------------------------
>>> UNIVERSITY OF CAPE TOWN
>>>
>>> This e-mail is subject to the UCT ICT policies and e-mail disclaimer
>>> published on our website at
>>> http://www.uct.ac.za/about/policies/emaildisclaimer/ or obtainable from +27
>>> 21 650 9111. This e-mail is intended only for the person(s) to whom it
>>> is addressed. If the e-mail has reached you in error, please notify the
>>> author. If you are not the intended recipient of the e-mail you may not
>>> use, disclose, copy, redirect or print the content. If this e-mail is not
>>> related to the business of UCT it is sent by the sender in the sender's
>>> individual capacity.
>>>
>>> _______________________________________________
>>> 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"
>>>
>>
>>
>> _______________________________________________
>> production mailing list
>> production at collab.sakaiproject.org
>> http://collab.sakaiproject.org/mailman/listinfo/production
>>
>> TO UNSUBSCRIBE: send email to
>> production-unsubscribe at collab.sakaiproject.org with a subject of
>> "unsubscribe"
>>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://collab.sakaiproject.org/pipermail/production/attachments/20140324/56ad0825/attachment-0001.html
More information about the production
mailing list