[
https://issues.apache.org/jira/browse/SOLR-15096?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17270454#comment-17270454
]
Mike Drob commented on SOLR-15096:
----------------------------------
Comparing logs from an 8x delete:
{noformat}
2021-01-22 21:36:49.195 INFO
(OverseerThreadFactory-18-thread-5-processing-n:10.0.0.160:8983_solr) [ ]
o.a.s.c.a.c.DeleteCollectionCmd Begin Delete Call
2021-01-22 21:36:49.196 INFO
(OverseerCollectionConfigSetProcessor-72063415443980288-10.0.0.160:8983_solr-n_0000000000)
[ ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may
have disconnected from ZooKeeper
2021-01-22 21:36:49.196 INFO
(OverseerThreadFactory-18-thread-5-processing-n:10.0.0.160:8983_solr) [ ]
o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection
Cmd=action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true&deleteMetricsHistory=true,
asyncId=null
2021-01-22 21:36:49.198 INFO (qtp952562199-27) [ x:coll-3_shard1_replica_n1]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.core.coll-3.shard1.replica_n1 tag=null
2021-01-22 21:36:49.198 INFO (qtp952562199-27) [ x:coll-3_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@5dd69a16: rootName = null,
domain = solr.core.coll-3.shard1.replica_n1, service url = null, agent id =
null] for registry
solr.core.coll-3.shard1.replica_n1/com.codahale.metrics.MetricRegistry@3928453
2021-01-22 21:36:49.201 INFO (qtp952562199-27) [ ] o.a.s.c.SolrCore
[coll-3_shard1_replica_n1] CLOSING SolrCore
org.apache.solr.core.SolrCore@78cdf733
2021-01-22 21:36:49.201 INFO (qtp952562199-27) [ ] o.a.s.m.SolrMetricManager
Closing metric reporters for registry=solr.core.coll-3.shard1.replica_n1
tag=SolrCore@78cdf733
2021-01-22 21:36:49.201 INFO (qtp952562199-27) [ ] o.a.s.m.SolrMetricManager
Closing metric reporters for registry=solr.collection.coll-3.shard1.leader
tag=SolrCore@78cdf733
2021-01-22 21:36:49.201 INFO (qtp952562199-27) [ ]
o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED
(unnecessary).
2021-01-22 21:36:49.205 INFO (qtp952562199-27) [ ] o.a.s.c.ZkShardTerms
Successful update of terms at /collections/coll-3/terms/shard1 to
Terms{values={}, version=1}
2021-01-22 21:36:49.207 INFO (qtp952562199-27) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={deleteInstanceDir=true&deleteMetricsHistory=true&core=coll-3_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2}
status=0 QTime=10
2021-01-22 21:36:49.209 INFO
(OverseerThreadFactory-18-thread-5-processing-n:10.0.0.160:8983_solr) [ ]
o.a.s.c.c.ZkStateReader Begin waiting for state
2021-01-22 21:36:49.209 INFO
(OverseerThreadFactory-18-thread-5-processing-n:10.0.0.160:8983_solr) [ ]
o.a.s.c.c.ZkStateReader already watching , added to stateWatchers
2021-01-22 21:36:49.312 INFO (zkCallback-10-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDeleted path:/collections/coll-3/state.json] for
collection [coll-3] has occurred - updating... (live nodes size: [1])
2021-01-22 21:36:49.312 INFO (zkCallback-10-thread-2) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDeleted path:/collections/coll-3/state.json] for
collection [coll-3] has occurred - updating... (live nodes size: [1])
2021-01-22 21:36:49.312 INFO (zkCallback-10-thread-3) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDeleted path:/collections/coll-3/state.json] for
collection [coll-3] has occurred - updating... (live nodes size: [1])
2021-01-22 21:36:49.312 INFO (zkCallback-10-thread-4) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDeleted path:/collections/coll-3/state.json] for
collection [coll-3] has occurred - updating... (live nodes size: [1])
2021-01-22 21:36:49.313 INFO
(OverseerThreadFactory-18-thread-5-processing-n:10.0.0.160:8983_solr) [ ]
o.a.s.c.c.ZkStateReader Exit waiting for state
2021-01-22 21:36:49.318 INFO
(OverseerThreadFactory-18-thread-5-processing-n:10.0.0.160:8983_solr) [ ]
o.a.s.c.a.c.DeleteCollectionCmd End Delete Call
2021-01-22 21:36:49.320 INFO (qtp952562199-30) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/collections params={name=coll-3&action=DELETE}
status=0 QTime=126
{noformat}
To a 9.0 delete
{noformat}
2021-01-22 21:30:30.632 INFO
(OverseerThreadFactory-15-thread-5-processing-n:localhost:8983_solr) [ ]
o.a.s.c.a.c.DeleteCollectionCmd Begin Delete Call
2021-01-22 21:30:30.657 INFO
(OverseerCollectionConfigSetProcessor-72063388558688256-localhost:8983_solr-n_0000000000)
[ ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may
have disconnected from ZooKeeper
2021-01-22 21:30:30.657 INFO
(OverseerThreadFactory-15-thread-5-processing-n:localhost:8983_solr) [ ]
o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection
Cmd=action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true&deleteMetricsHistory=true,
asyncId=null
2021-01-22 21:30:30.682 INFO (qtp1817789863-27) [
x:coll-3_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.core.coll-3.shard1.replica_n1 tag=null
2021-01-22 21:30:30.682 INFO (qtp1817789863-27) [
x:coll-3_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@f3bb32b: rootName = null,
domain = solr.core.coll-3.shard1.replica_n1, service url = null, agent id =
null] for registry
solr.core.coll-3.shard1.replica_n1/com.codahale.metrics.MetricRegistry@31ca9062
2021-01-22 21:30:30.734 INFO (qtp1817789863-27) [
x:coll-3_shard1_replica_n1] o.a.s.m.SolrMetricManager Finished closing,
elapsed=52
2021-01-22 21:30:30.734 INFO (qtp1817789863-27) [ ] o.a.s.c.SolrCore
[coll-3_shard1_replica_n1] CLOSING SolrCore
org.apache.solr.core.SolrCore@1d0c826c
2021-01-22 21:30:30.735 INFO (qtp1817789863-27) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.core.coll-3.shard1.replica_n1 tag=SolrCore@1d0c826c
2021-01-22 21:30:30.735 INFO (qtp1817789863-27) [ ]
o.a.s.m.SolrMetricManager Finished closing, elapsed=1
2021-01-22 21:30:30.735 INFO (qtp1817789863-27) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.collection.coll-3.shard1.leader tag=SolrCore@1d0c826c
2021-01-22 21:30:30.735 INFO (qtp1817789863-27) [ ]
o.a.s.m.SolrMetricManager Finished closing, elapsed=0
2021-01-22 21:30:30.735 INFO (qtp1817789863-27) [ ]
o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED
(unnecessary).
2021-01-22 21:30:30.763 INFO (qtp1817789863-27) [ ] o.a.s.c.ZkShardTerms
Successful update of terms at /collections/coll-3/terms/shard1 to
Terms{values={}, version=1} for removeTerm
2021-01-22 21:30:30.837 INFO (qtp1817789863-27) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={deleteInstanceDir=true&deleteMetricsHistory=true&core=coll-3_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2}
status=0 QTime=178
2021-01-22 21:30:30.864 INFO
(OverseerThreadFactory-15-thread-5-processing-n:localhost:8983_solr) [ ]
o.a.s.c.c.ZkStateReader Entered waiting for state
2021-01-22 21:30:30.994 INFO (zkCallback-9-thread-4) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDeleted path:/collections/coll-3/state.json] for
collection [coll-3] has occurred - updating... (live nodes size: [1])
2021-01-22 21:30:30.994 INFO (zkCallback-9-thread-2) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDeleted path:/collections/coll-3/state.json] for
collection [coll-3] has occurred - updating... (live nodes size: [1])
2021-01-22 21:30:30.994 INFO (zkCallback-9-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDeleted path:/collections/coll-3/state.json] for
collection [coll-3] has occurred - updating... (live nodes size: [1])
2021-01-22 21:30:30.994 INFO (zkCallback-9-thread-3) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDeleted path:/collections/coll-3/state.json] for
collection [coll-3] has occurred - updating... (live nodes size: [1])
2021-01-22 21:30:31.019 INFO
(OverseerThreadFactory-15-thread-5-processing-n:localhost:8983_solr) [ ]
o.a.s.c.c.ZkStateReader Exit waiting for state
2021-01-22 21:30:31.226 INFO
(OverseerThreadFactory-15-thread-5-processing-n:localhost:8983_solr) [ ]
o.a.s.c.a.c.DeleteCollectionCmd End Delete Call
2021-01-22 21:30:31.295 INFO (qtp1817789863-31) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/collections params={name=coll-3&action=DELETE}
status=0 QTime=711
{noformat}
> [REGRESSION] Collection Delete Performance significantly degraded in 9.0 v 8.8
> ------------------------------------------------------------------------------
>
> Key: SOLR-15096
> URL: https://issues.apache.org/jira/browse/SOLR-15096
> Project: Solr
> Issue Type: Bug
> Affects Versions: master (9.0)
> Reporter: Mike Drob
> Priority: Blocker
> Fix For: master (9.0)
>
> Attachments: Screen Shot 2021-01-21 at 5.44.25 PM.png
>
>
> While doing some other performance testing I noticed that collection deletion
> in 8.8 (RC1) would take approximately 200ms, while the same operation would
> take 800ms using a recent snapshot ({{a233ed2fd1b}}) from master branch.
> I have not done further investigation at this time.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscr...@lucene.apache.org
For additional commands, e-mail: issues-h...@lucene.apache.org
