[NEXUS-17501] Caching of NuGet metadata causes thread serialization, query slowdowns under load - Sonatype JIRA

XML

Word

Printable

Details

Type: Bug
Status: Closed
Priority: Major
Resolution: Fixed
Affects Version/s: 3.8.0, 3.13.0, 3.14.0
Fix Version/s: 3.15.0
Component/s: Database, NuGet
Labels:
- performance
- supportant

Story Points:
3

Description

Threads updating NuGet metadata are getting be serialized, as can be seen in the examples below. This is causing a slowdown in processing of NuGet queries.

This was observed in Nexus Repo 3.8.0-02.

Full thread dump is attached. In that thread dump there are 5 threads waiting on the one that is running.

qtp109915384-3713 <command>sql.select from component where (ci_name = :p0 AND version = :p1) and (bucket=#24:6)</command> id=3713 state=RUNNABLE
    at java.lang.ThreadLocal$ThreadLocalMap.cleanSomeSlots(ThreadLocal.java:661)
    at java.lang.ThreadLocal$ThreadLocalMap.set(ThreadLocal.java:483)
    at java.lang.ThreadLocal$ThreadLocalMap.access$100(ThreadLocal.java:298)
    at java.lang.ThreadLocal.set(ThreadLocal.java:203)
    at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryAcquireShared(ReentrantReadWriteLock.java:483)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282)
    at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:727)
    at com.orientechnologies.common.concur.resource.OSharedResourceAdaptive.acquireSharedLock(OSharedResourceAdaptive.java:168)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OClusterPositionMap.get(OClusterPositionMap.java:385)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedCluster.readRecord(OPaginatedCluster.java:681)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedCluster.readRecord(OPaginatedCluster.java:668)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.doReadRecord(OAbstractPaginatedStorage.java:4203)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.readRecord(OAbstractPaginatedStorage.java:3819)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.readRecord(OAbstractPaginatedStorage.java:1409)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx$SimpleRecordReader.readRecord(ODatabaseDocumentTx.java:3411)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.executeReadRecord(ODatabaseDocumentTx.java:2022)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.load(ODatabaseDocumentTx.java:660)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.load(ODatabaseDocumentTx.java:103)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearchRecord(OCommandExecutorSQLSelect.java:585)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.serialIterator(OCommandExecutorSQLSelect.java:1638)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.fetchFromTarget(OCommandExecutorSQLSelect.java:1585)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.fetchValuesFromIndexCursor(OCommandExecutorSQLSelect.java:2466)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.searchForIndexes(OCommandExecutorSQLSelect.java:2280)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.searchInClasses(OCommandExecutorSQLSelect.java:1017)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetAbstract.assignTarget(OCommandExecutorSQLResultsetAbstract.java:211)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.assignTarget(OCommandExecutorSQLSelect.java:527)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:509)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.execute(OCommandExecutorSQLSelect.java:485)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.execute(OCommandExecutorSQLDelegate.java:70)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.executeCommand(OAbstractPaginatedStorage.java:3417)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.command(OAbstractPaginatedStorage.java:3335)
    at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:69)
    at org.sonatype.nexus.repository.storage.MetadataNodeEntityAdapter.browseByQuery(MetadataNodeEntityAdapter.java:178)
    at org.sonatype.nexus.repository.storage.StorageTxImpl.findComponents(StorageTxImpl.java:431)
    at org.sonatype.nexus.repository.storage.StorageTxImpl.findComponents(StorageTxImpl.java:437)
    at sun.reflect.GeneratedMethodAccessor398.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.sonatype.nexus.common.stateguard.SimpleMethodInvocation.proceed(SimpleMethodInvocation.java:53)
    at org.sonatype.nexus.common.stateguard.MethodInvocationAction.run(MethodInvocationAction.java:39)
    at org.sonatype.nexus.common.stateguard.StateGuard$GuardImpl.run(StateGuard.java:270)
    at org.sonatype.nexus.common.stateguard.GuardedInterceptor.invoke(GuardedInterceptor.java:53)
    at org.sonatype.nexus.common.stateguard.StateGuardAspect$1.invoke(StateGuardAspect.java:63)
    at com.sun.proxy.$Proxy190.findComponents(Unknown Source)
    at com.sonatype.nexus.repository.nuget.NugetComponentHelper.findComponent(NugetComponentHelper.java:71)
    at com.sonatype.nexus.repository.nuget.internal.NugetLocalGalleryFacetSupport.findComponent(NugetLocalGalleryFacetSupport.java:756)
    at com.sonatype.nexus.repository.nuget.internal.NugetLocalGalleryFacetSupport.findOrCreateComponent(NugetLocalGalleryFacetSupport.java:746)
    at com.sonatype.nexus.repository.nuget.internal.NugetLocalGalleryFacetSupport.createOrUpdateComponent(NugetLocalGalleryFacetSupport.java:681)
    at com.sonatype.nexus.repository.nuget.internal.NugetLocalGalleryFacetSupport.putMetadata(NugetLocalGalleryFacetSupport.java:304)
    at com.sonatype.nexus.repository.nuget.internal.proxy.NugetProxyGalleryFacet$$EnhancerByGuice$$6170df17.CGLIB$putMetadata$23(<generated>)
    at com.sonatype.nexus.repository.nuget.internal.proxy.NugetProxyGalleryFacet$$EnhancerByGuice$$6170df17$$FastClassByGuice$$56084185.invoke(<generated>)
    at com.google.inject.internal.cglib.proxy.$MethodProxy.invokeSuper(MethodProxy.java:228)
    at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:76)
    at org.sonatype.nexus.transaction.TransactionalWrapper.proceedWithTransaction(TransactionalWrapper.java:56)
    at org.sonatype.nexus.transaction.TransactionInterceptor.invoke(TransactionInterceptor.java:54)
    at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:77)
    at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:55)
    at com.sonatype.nexus.repository.nuget.internal.proxy.NugetProxyGalleryFacet$$EnhancerByGuice$$6170df17.putMetadata(<generated>)
    at com.sonatype.nexus.repository.nuget.internal.NugetRemoteGalleryFacetSupport$FeedLoader$1.consume(NugetRemoteGalleryFacetSupport.java:394)
    at com.sonatype.nexus.repository.nuget.odata.FeedSplicer.ended(FeedSplicer.java:109)
    at com.sonatype.nexus.repository.nuget.odata.XmlSplicer.consume(XmlSplicer.java:81)
    at com.sonatype.nexus.repository.nuget.odata.FeedSplicer.consumePage(FeedSplicer.java:58)
    at com.sonatype.nexus.repository.nuget.internal.NugetFeedFetcher.parseFeed(NugetFeedFetcher.java:103)
    at com.sonatype.nexus.repository.nuget.internal.NugetFeedFetcher.cachePackageFeed(NugetFeedFetcher.java:86)
    at com.sonatype.nexus.repository.nuget.internal.NugetRemoteGalleryFacetSupport$FeedLoader.call(NugetRemoteGalleryFacetSupport.java:390)
    at com.sonatype.nexus.repository.nuget.internal.NugetRemoteGalleryFacetSupport.passQueryToRemoteRepos(NugetRemoteGalleryFacetSupport.java:325)
    at com.sonatype.nexus.repository.nuget.internal.NugetRemoteGalleryFacetSupport.feed(NugetRemoteGalleryFacetSupport.java:204)
    at com.sonatype.nexus.repository.nuget.internal.NugetFeedHandler.feed(NugetFeedHandler.java:69)
    at com.sonatype.nexus.repository.nuget.internal.NugetFeedHandler.doHandle(NugetFeedHandler.java:49)

Example blocked thread:

qtp109915384-4057 <command>sql.select from component where (ci_name = :p0 AND version = :p1) and (bucket=#24:6)</command> id=4057 state=WAITING
    - waiting on <0x04a9cd87> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
    - locked <0x04a9cd87> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
    at sun.misc.Unsafe.park(Native Method)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
    at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:943)
    at com.orientechnologies.common.concur.lock.OPartitionedLockManager.acquireExclusiveLock(OPartitionedLockManager.java:213)
    at com.orientechnologies.common.concur.lock.OPartitionedLockManager.acquireExclusiveLocksInBatch(OPartitionedLockManager.java:266)
    at com.orientechnologies.orient.core.storage.cache.local.twoq.O2QCache.doLoad(O2QCache.java:343)
    at com.orientechnologies.orient.core.storage.cache.local.twoq.O2QCache.load(O2QCache.java:294)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.base.ODurableComponent.loadPage(ODurableComponent.java:148)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedCluster.readRecordBuffer(OPaginatedCluster.java:713)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedCluster.readRecord(OPaginatedCluster.java:689)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedCluster.readRecord(OPaginatedCluster.java:668)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.doReadRecord(OAbstractPaginatedStorage.java:4203)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.readRecord(OAbstractPaginatedStorage.java:3819)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.readRecord(OAbstractPaginatedStorage.java:1409)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx$SimpleRecordReader.readRecord(ODatabaseDocumentTx.java:3411)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.executeReadRecord(ODatabaseDocumentTx.java:2022)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.load(ODatabaseDocumentTx.java:660)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.load(ODatabaseDocumentTx.java:103)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearchRecord(OCommandExecutorSQLSelect.java:585)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.serialIterator(OCommandExecutorSQLSelect.java:1638)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.fetchFromTarget(OCommandExecutorSQLSelect.java:1585)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.fetchValuesFromIndexCursor(OCommandExecutorSQLSelect.java:2466)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.searchForIndexes(OCommandExecutorSQLSelect.java:2280)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.searchInClasses(OCommandExecutorSQLSelect.java:1017)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetAbstract.assignTarget(OCommandExecutorSQLResultsetAbstract.java:211)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.assignTarget(OCommandExecutorSQLSelect.java:527)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:509)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.execute(OCommandExecutorSQLSelect.java:485)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.execute(OCommandExecutorSQLDelegate.java:70)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.executeCommand(OAbstractPaginatedStorage.java:3417)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.command(OAbstractPaginatedStorage.java:3335)
    at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:69)
    at org.sonatype.nexus.repository.storage.MetadataNodeEntityAdapter.browseByQuery(MetadataNodeEntityAdapter.java:178)
    at org.sonatype.nexus.repository.storage.StorageTxImpl.findComponents(StorageTxImpl.java:431)
    at org.sonatype.nexus.repository.storage.StorageTxImpl.findComponents(StorageTxImpl.java:437)
    at sun.reflect.GeneratedMethodAccessor398.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.sonatype.nexus.common.stateguard.SimpleMethodInvocation.proceed(SimpleMethodInvocation.java:53)
    at org.sonatype.nexus.common.stateguard.MethodInvocationAction.run(MethodInvocationAction.java:39)
    at org.sonatype.nexus.common.stateguard.StateGuard$GuardImpl.run(StateGuard.java:270)
    at org.sonatype.nexus.common.stateguard.GuardedInterceptor.invoke(GuardedInterceptor.java:53)
    at org.sonatype.nexus.common.stateguard.StateGuardAspect$1.invoke(StateGuardAspect.java:63)
    at com.sun.proxy.$Proxy190.findComponents(Unknown Source)
    at com.sonatype.nexus.repository.nuget.NugetComponentHelper.findComponent(NugetComponentHelper.java:71)
    at com.sonatype.nexus.repository.nuget.internal.NugetLocalGalleryFacetSupport.findComponent(NugetLocalGalleryFacetSupport.java:756)
    at com.sonatype.nexus.repository.nuget.internal.NugetLocalGalleryFacetSupport.findOrCreateComponent(NugetLocalGalleryFacetSupport.java:746)
    at com.sonatype.nexus.repository.nuget.internal.NugetLocalGalleryFacetSupport.createOrUpdateComponent(NugetLocalGalleryFacetSupport.java:681)
    at com.sonatype.nexus.repository.nuget.internal.NugetLocalGalleryFacetSupport.putMetadata(NugetLocalGalleryFacetSupport.java:304)
    at com.sonatype.nexus.repository.nuget.internal.proxy.NugetProxyGalleryFacet$$EnhancerByGuice$$6170df17.CGLIB$putMetadata$23(<generated>)
    at com.sonatype.nexus.repository.nuget.internal.proxy.NugetProxyGalleryFacet$$EnhancerByGuice$$6170df17$$FastClassByGuice$$56084185.invoke(<generated>)
    at com.google.inject.internal.cglib.proxy.$MethodProxy.invokeSuper(MethodProxy.java:228)
    at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:76)
    at org.sonatype.nexus.transaction.TransactionalWrapper.proceedWithTransaction(TransactionalWrapper.java:56)
    at org.sonatype.nexus.transaction.TransactionInterceptor.invoke(TransactionInterceptor.java:54)
    at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:77)
    at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:55)
    at com.sonatype.nexus.repository.nuget.internal.proxy.NugetProxyGalleryFacet$$EnhancerByGuice$$6170df17.putMetadata(<generated>)
    at com.sonatype.nexus.repository.nuget.internal.NugetRemoteGalleryFacetSupport$FeedLoader$1.consume(NugetRemoteGalleryFacetSupport.java:394)
    at com.sonatype.nexus.repository.nuget.odata.FeedSplicer.ended(FeedSplicer.java:109)
    at com.sonatype.nexus.repository.nuget.odata.XmlSplicer.consume(XmlSplicer.java:81)
    at com.sonatype.nexus.repository.nuget.odata.FeedSplicer.consumePage(FeedSplicer.java:58)
    at com.sonatype.nexus.repository.nuget.internal.NugetFeedFetcher.parseFeed(NugetFeedFetcher.java:103)
    at com.sonatype.nexus.repository.nuget.internal.NugetFeedFetcher.cachePackageFeed(NugetFeedFetcher.java:86)
    at com.sonatype.nexus.repository.nuget.internal.NugetRemoteGalleryFacetSupport$FeedLoader.call(NugetRemoteGalleryFacetSupport.java:390)
    at com.sonatype.nexus.repository.nuget.internal.NugetRemoteGalleryFacetSupport.passQueryToRemoteRepos(NugetRemoteGalleryFacetSupport.java:325)
    at com.sonatype.nexus.repository.nuget.internal.NugetRemoteGalleryFacetSupport.feed(NugetRemoteGalleryF

Attachments

Options
- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

Attachments

threads.txt
299 kB
06/29/18 05:09 PM

Issue Links

relates

NEXUS-18083 potential slow processing of concurrent nuget requests using FindPackagesById()

Closed

Activity

People

Assignee:: Joseph Stephens

Reporter:: Rich Seddon

Last Updated By:: Peter Lynch

Team:: NXRM - Cypher

Votes:: 0 Vote for this issue

Watchers:: 7 Start watching this issue

Dates

Created:: 06/29/18 05:10 PM

Updated:: 12/19/19 03:27 PM

Resolved:: 10/03/18 12:57 PM

Date of First Response:: 03/Jul/18 1:37 PM

Details

Description

Attachments

Attachments

Issue Links

Activity

People

Dates

tigCommentSecurity.panel-title