Varun Thacker created SOLR-11686:
------------------------------------
Summary: Make collection creation logging less verbose
Key: SOLR-11686
URL: https://issues.apache.org/jira/browse/SOLR-11686
Project: Solr
Issue Type: Improvement
Security Level: Public (Default Security Level. Issues are Public)
Reporter: Varun Thacker
Assignee: Varun Thacker
Here's roughly what get's logged :
{code}
INFO - 2017-11-27 21:55:09.685; [ ]
org.apache.solr.handler.admin.CollectionsHandler; Invoked Collection Action
:create with params
replicationFactor=1&maxShardsPerNode=-1&collection.configName=test&name=test&action=CREATE&numShards=1&wt=json
and sendToOCPQueue=true
INFO - 2017-11-27 21:55:09.719; [ ]
org.apache.solr.cloud.CreateCollectionCmd; Create collection test
INFO - 2017-11-27 21:55:09.928; [ ]
org.apache.solr.cloud.overseer.SliceMutator; createReplica() {
"operation":"ADDREPLICA",
"collection":"test",
"shard":"shard1",
"core":"test_shard1_replica_n1",
"state":"down",
"base_url":"http://172.16.0.83:8983/solr";,
"type":"NRT"}
INFO - 2017-11-27 21:55:10.187; [ ]
org.apache.solr.handler.admin.CoreAdminOperation; core create command
qt=/admin/cores&coreNodeName=core_node2&collection.configName=test&newCollection=true&name=test_shard1_replica_n1&action=CREATE&numShards=1&collection=test&shard=shard1&wt=javabin&version=2&replicaType=NRT
INFO - 2017-11-27 21:55:10.190; [ ]
org.apache.solr.core.TransientSolrCoreCacheDefault; Allocating transient cache
for 2147483647 transient cores
INFO - 2017-11-27 21:55:10.357; [ ]
org.apache.solr.common.cloud.ZkStateReader$StateWatcher; A cluster state
change: [WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test/state.json] for collection [test] has occurred -
updating... (live nodes size: [1])
INFO - 2017-11-27 21:55:10.357; [ ]
org.apache.solr.common.cloud.ZkStateReader$StateWatcher; A cluster state
change: [WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test/state.json] for collection [test] has occurred -
updating... (live nodes size: [1])
INFO - 2017-11-27 21:55:11.256; [ ] org.apache.solr.core.RequestParams; conf
resource params.json loaded . version : 0
INFO - 2017-11-27 21:55:11.257; [ ] org.apache.solr.core.RequestParams;
request params refreshed to version 0
INFO - 2017-11-27 21:55:11.272; [ ] org.apache.solr.core.SolrResourceLoader;
[test_shard1_replica_n1] Added 53 libs to classloader, from paths:
[/Users/varunthacker/solr-7.1.0/contrib/clustering/lib,
/Users/varunthacker/solr-7.1.0/contrib/extraction/lib,
/Users/varunthacker/solr-7.1.0/contrib/langid/lib,
/Users/varunthacker/solr-7.1.0/contrib/velocity/lib,
/Users/varunthacker/solr-7.1.0/dist]
INFO - 2017-11-27 21:55:11.479; [ ] org.apache.solr.core.SolrConfig; Using
Lucene MatchVersion: 7.1.0
INFO - 2017-11-27 21:55:11.616; [ ] org.apache.solr.schema.IndexSchema;
[test_shard1_replica_n1] Schema name=default-config
INFO - 2017-11-27 21:55:12.161; [ ] org.apache.solr.schema.IndexSchema;
Loaded schema default-config/1.6 with uniqueid field id
INFO - 2017-11-27 21:55:12.206; [ ] org.apache.solr.core.CoreContainer;
Creating SolrCore 'test_shard1_replica_n1' using configuration from collection
test, trusted=true
INFO - 2017-11-27 21:55:12.230; [ ] org.apache.solr.core.SolrCore;
solr.RecoveryStrategy.Builder
INFO - 2017-11-27 21:55:12.235; [ ] org.apache.solr.core.SolrCore;
[[test_shard1_replica_n1] ] Opening new SolrCore at
[/Users/varunthacker/solr-7.1.0/example/cloud/node1/solr/test_shard1_replica_n1],
dataDir=[/Users/varunthacker/solr-7.1.0/example/cloud/node1/solr/test_shard1_replica_n1/data/]
INFO - 2017-11-27 21:55:12.338; [ ]
org.apache.solr.response.XSLTResponseWriter; xsltCacheLifetimeSeconds=5
INFO - 2017-11-27 21:55:12.641; [ ] org.apache.solr.update.UpdateHandler;
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
INFO - 2017-11-27 21:55:12.641; [ ] org.apache.solr.update.UpdateLog;
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
INFO - 2017-11-27 21:55:12.649; [ ] org.apache.solr.update.CommitTracker;
Hard AutoCommit: if uncommited for 15000ms;
INFO - 2017-11-27 21:55:12.649; [ ] org.apache.solr.update.CommitTracker;
Soft AutoCommit: disabled
INFO - 2017-11-27 21:55:12.668; [ ]
org.apache.solr.search.SolrIndexSearcher; Opening
[Searcher@70fa64c2[test_shard1_replica_n1] main]
INFO - 2017-11-27 21:55:12.681; [ ]
org.apache.solr.rest.ManagedResourceStorage$ZooKeeperStorageIO; Configured
ZooKeeperStorageIO with znodeBase: /configs/test
INFO - 2017-11-27 21:55:12.694; [ ]
org.apache.solr.rest.ManagedResourceStorage; Loaded null at path
_rest_managed.json using ZooKeeperStorageIO:path=/configs/test
INFO - 2017-11-27 21:55:12.695; [ ]
org.apache.solr.schema.ZkIndexSchemaReader; Creating ZooKeeper watch for the
managed schema at /configs/test/managed-schema
INFO - 2017-11-27 21:55:12.696; [ ]
org.apache.solr.schema.ZkIndexSchemaReader; Current schema version 0 is already
the latest
INFO - 2017-11-27 21:55:12.703; [ ]
org.apache.solr.handler.component.SpellCheckComponent; Initializing spell
checkers
INFO - 2017-11-27 21:55:12.708; [ ]
org.apache.solr.spelling.DirectSolrSpellChecker; init:
{name=default,field=_text_,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
INFO - 2017-11-27 21:55:12.717; [ ]
org.apache.solr.handler.ReplicationHandler; Commits will be reserved for
10000ms.
INFO - 2017-11-27 21:55:12.789; [ ]
org.apache.solr.core.QuerySenderListener; QuerySenderListener sending requests
to Searcher@70fa64c2[test_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
INFO - 2017-11-27 21:55:12.789; [ ]
org.apache.solr.core.QuerySenderListener; QuerySenderListener done.
INFO - 2017-11-27 21:55:12.789; [ ]
org.apache.solr.handler.component.SpellCheckComponent$SpellCheckerListener;
Loading spell index for spellchecker: default
INFO - 2017-11-27 21:55:12.796; [ ] org.apache.solr.update.UpdateLog; Could
not find max version in index or recent updates, using new clock
1585257867164778496
INFO - 2017-11-27 21:55:12.797; [ ] org.apache.solr.core.SolrCore;
[test_shard1_replica_n1] Registered new searcher
Searcher@70fa64c2[test_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
INFO - 2017-11-27 21:55:12.861; [ ]
org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to
continue.
INFO - 2017-11-27 21:55:12.861; [ ]
org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try
and sync
INFO - 2017-11-27 21:55:12.862; [ ] org.apache.solr.cloud.SyncStrategy; Sync
replicas to http://172.16.0.83:8983/solr/test_shard1_replica_n1/
INFO - 2017-11-27 21:55:12.863; [ ] org.apache.solr.cloud.SyncStrategy; Sync
Success - now sync replicas to me
INFO - 2017-11-27 21:55:12.863; [ ] org.apache.solr.cloud.SyncStrategy;
http://172.16.0.83:8983/solr/test_shard1_replica_n1/ has no replicas
INFO - 2017-11-27 21:55:12.863; [ ]
org.apache.solr.cloud.ShardLeaderElectionContext; Found all replicas
participating in election, clear LIR
INFO - 2017-11-27 21:55:12.930; [ ]
org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader:
http://172.16.0.83:8983/solr/test_shard1_replica_n1/ shard1
INFO - 2017-11-27 21:55:12.967; [ ]
org.apache.solr.common.cloud.ZkStateReader$StateWatcher; A cluster state
change: [WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test/state.json] for collection [test] has occurred -
updating... (live nodes size: [1])
INFO - 2017-11-27 21:55:12.967; [ ]
org.apache.solr.common.cloud.ZkStateReader$StateWatcher; A cluster state
change: [WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test/state.json] for collection [test] has occurred -
updating... (live nodes size: [1])
INFO - 2017-11-27 21:55:12.986; [ ] org.apache.solr.cloud.ZkController; I am
the leader, no recovery necessary
INFO - 2017-11-27 21:55:13.001; [ ] org.apache.solr.servlet.HttpSolrCall;
[admin] webapp=null path=/admin/cores
params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=test&newCollection=true&name=test_shard1_replica_n1&action=CREATE&numShards=1&collection=test&shard=shard1&wt=javabin&version=2&replicaType=NRT}
status=0 QTime=2815
INFO - 2017-11-27 21:55:13.090; [ ]
org.apache.solr.handler.admin.CollectionsHandler; Wait for new collection to be
active for at most 30 seconds. Check all shard replicas
INFO - 2017-11-27 21:55:13.146; [ ]
org.apache.solr.common.cloud.ZkStateReader$StateWatcher; A cluster state
change: [WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test/state.json] for collection [test] has occurred -
updating... (live nodes size: [1])
INFO - 2017-11-27 21:55:13.146; [ ]
org.apache.solr.common.cloud.ZkStateReader$StateWatcher; A cluster state
change: [WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/test/state.json] for collection [test] has occurred -
updating... (live nodes size: [1])
INFO - 2017-11-27 21:55:13.735; [ ] org.apache.solr.cloud.OverseerTaskQueue;
Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist.
Requestor may have disconnected from ZooKeeper
INFO - 2017-11-27 21:55:14.095; [ ] org.apache.solr.servlet.HttpSolrCall;
[admin] webapp=null path=/admin/collections
params={replicationFactor=1&maxShardsPerNode=-1&collection.configName=test&name=test&action=CREATE&numShards=1&wt=json}
status=0 QTime=4410
INFO - 2017-11-27 21:55:14.175; [ ]
org.apache.solr.handler.SolrConfigHandler$Command; Executed config commands
successfully and persisted to ZK
[{"set-property":{"updateHandler.autoSoftCommit.maxTime":"3000"}}]
INFO - 2017-11-27 21:55:14.176; [ ] org.apache.solr.core.SolrCore; config
update listener called for core test_shard1_replica_n1
INFO - 2017-11-27 21:55:14.177; [ ]
org.apache.solr.handler.SolrConfigHandler; Waiting up to 30 secs for 1 replicas
to set the property overlay to be of version 0 for collection test
INFO - 2017-11-27 21:55:14.177; [ ] org.apache.solr.core.SolrCore; core
reload test_shard1_replica_n1
INFO - 2017-11-27 21:55:14.178; [ ]
org.apache.solr.handler.SolrConfigHandler$PerReplicaCallable; Time elapsed : 0
secs, maxWait 30
INFO - 2017-11-27 21:55:14.195; [ ] org.apache.solr.core.RequestParams; conf
resource params.json loaded . version : 0
INFO - 2017-11-27 21:55:14.195; [ ] org.apache.solr.core.RequestParams;
request params refreshed to version 0
INFO - 2017-11-27 21:55:14.198; [ ] org.apache.solr.core.SolrResourceLoader;
[test_shard1_replica_n1] Added 53 libs to classloader, from paths:
[/Users/varunthacker/solr-7.1.0/contrib/clustering/lib,
/Users/varunthacker/solr-7.1.0/contrib/extraction/lib,
/Users/varunthacker/solr-7.1.0/contrib/langid/lib,
/Users/varunthacker/solr-7.1.0/contrib/velocity/lib,
/Users/varunthacker/solr-7.1.0/dist]
INFO - 2017-11-27 21:55:14.222; [ ] org.apache.solr.core.SolrConfig; Using
Lucene MatchVersion: 7.1.0
INFO - 2017-11-27 21:55:14.256; [ ] org.apache.solr.schema.IndexSchema;
[test_shard1_replica_n1] Schema name=default-config
INFO - 2017-11-27 21:55:14.289; [ ]
org.apache.solr.handler.SolrConfigHandler$Command; expecting overlay version 0
but my version is -1
INFO - 2017-11-27 21:55:14.291; [ ] org.apache.solr.core.SolrCore;
[test_shard1_replica_n1] webapp=/solr path=/config/znodeVersion
params={overlay=0&wt=javabin&version=2} status=0 QTime=1
INFO - 2017-11-27 21:55:14.291; [ ]
org.apache.solr.handler.SolrConfigHandler$Command; Another reload is in
progress . Not doing anything
INFO - 2017-11-27 21:55:14.292; [ ]
org.apache.solr.handler.SolrConfigHandler$PerReplicaCallable; Could not get
expectedVersion 0 from http://172.16.0.83:8983/solr/test_shard1_replica_n1/ for
prop overlay after 1 attempts
INFO - 2017-11-27 21:55:14.293; [ ]
org.apache.solr.handler.SolrConfigHandler$PerReplicaCallable; Time elapsed : 0
secs, maxWait 30
INFO - 2017-11-27 21:55:14.398; [ ]
org.apache.solr.handler.SolrConfigHandler$Command; expecting overlay version 0
but my version is -1
INFO - 2017-11-27 21:55:14.399; [ ]
org.apache.solr.handler.SolrConfigHandler$Command; Another reload is in
progress . Not doing anything
INFO - 2017-11-27 21:55:14.399; [ ] org.apache.solr.core.SolrCore;
[test_shard1_replica_n1] webapp=/solr path=/config/znodeVersion
params={overlay=0&wt=javabin&version=2} status=0 QTime=0
INFO - 2017-11-27 21:55:14.400; [ ]
org.apache.solr.handler.SolrConfigHandler$PerReplicaCallable; Could not get
expectedVersion 0 from http://172.16.0.83:8983/solr/test_shard1_replica_n1/ for
prop overlay after 2 attempts
INFO - 2017-11-27 21:55:14.400; [ ]
org.apache.solr.handler.SolrConfigHandler$PerReplicaCallable; Time elapsed : 0
secs, maxWait 30
INFO - 2017-11-27 21:55:14.428; [ ] org.apache.solr.schema.IndexSchema;
Loaded schema default-config/1.6 with uniqueid field id
INFO - 2017-11-27 21:55:14.465; [ ] org.apache.solr.core.CoreContainer;
Reloading SolrCore 'test_shard1_replica_n1' using configuration from collection
test
INFO - 2017-11-27 21:55:14.466; [ ] org.apache.solr.core.SolrCore;
[[test_shard1_replica_n1] ] Opening new SolrCore at
[/Users/varunthacker/solr-7.1.0/example/cloud/node1/solr/test_shard1_replica_n1],
dataDir=[/Users/varunthacker/solr-7.1.0/example/cloud/node1/solr/test_shard1_replica_n1/data/]
INFO - 2017-11-27 21:55:14.468; [ ]
org.apache.solr.response.XSLTResponseWriter; xsltCacheLifetimeSeconds=5
INFO - 2017-11-27 21:55:14.498; [ ] org.apache.solr.update.CommitTracker;
Hard AutoCommit: if uncommited for 15000ms;
INFO - 2017-11-27 21:55:14.499; [ ] org.apache.solr.update.CommitTracker;
Soft AutoCommit: if uncommited for 3000ms;
INFO - 2017-11-27 21:55:14.501; [ ]
org.apache.solr.search.SolrIndexSearcher; Opening
[Searcher@78ca9301[test_shard1_replica_n1] main]
INFO - 2017-11-27 21:55:14.503; [ ]
org.apache.solr.rest.ManagedResourceStorage$ZooKeeperStorageIO; Configured
ZooKeeperStorageIO with znodeBase: /configs/test
INFO - 2017-11-27 21:55:14.504; [ ]
org.apache.solr.rest.ManagedResourceStorage; Loaded null at path
_rest_managed.json using ZooKeeperStorageIO:path=/configs/test
INFO - 2017-11-27 21:55:14.504; [ ]
org.apache.solr.schema.ZkIndexSchemaReader; Creating ZooKeeper watch for the
managed schema at /configs/test/managed-schema
INFO - 2017-11-27 21:55:14.505; [ ]
org.apache.solr.handler.SolrConfigHandler$Command; expecting overlay version 0
but my version is -1
INFO - 2017-11-27 21:55:14.505; [ ]
org.apache.solr.schema.ZkIndexSchemaReader; Current schema version 0 is already
the latest
INFO - 2017-11-27 21:55:14.505; [ ] org.apache.solr.core.SolrCore;
[test_shard1_replica_n1] webapp=/solr path=/config/znodeVersion
params={overlay=0&wt=javabin&version=2} status=0 QTime=0
INFO - 2017-11-27 21:55:14.505; [ ]
org.apache.solr.handler.SolrConfigHandler$Command; Another reload is in
progress . Not doing anything
INFO - 2017-11-27 21:55:14.505; [ ]
org.apache.solr.handler.component.SpellCheckComponent; Initializing spell
checkers
INFO - 2017-11-27 21:55:14.506; [ ]
org.apache.solr.spelling.DirectSolrSpellChecker; init:
{name=default,field=_text_,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
INFO - 2017-11-27 21:55:14.507; [ ]
org.apache.solr.handler.SolrConfigHandler$PerReplicaCallable; Could not get
expectedVersion 0 from http://172.16.0.83:8983/solr/test_shard1_replica_n1/ for
prop overlay after 3 attempts
INFO - 2017-11-27 21:55:14.507; [ ]
org.apache.solr.handler.SolrConfigHandler$PerReplicaCallable; Time elapsed : 0
secs, maxWait 30
INFO - 2017-11-27 21:55:14.508; [ ]
org.apache.solr.handler.ReplicationHandler; Commits will be reserved for
10000ms.
INFO - 2017-11-27 21:55:14.509; [ ]
org.apache.solr.core.QuerySenderListener; QuerySenderListener sending requests
to Searcher@78ca9301[test_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
INFO - 2017-11-27 21:55:14.510; [ ]
org.apache.solr.core.QuerySenderListener; QuerySenderListener done.
INFO - 2017-11-27 21:55:14.510; [ ]
org.apache.solr.handler.component.SpellCheckComponent$SpellCheckerListener;
Loading spell index for spellchecker: default
INFO - 2017-11-27 21:55:14.510; [ ] org.apache.solr.update.UpdateLog; Could
not find max version in index or recent updates, using new clock
1585257868962037760
INFO - 2017-11-27 21:55:14.510; [ ] org.apache.solr.core.SolrCore;
[test_shard1_replica_n1] Registered new searcher
Searcher@78ca9301[test_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
INFO - 2017-11-27 21:55:14.517; [ ]
org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be
used.
INFO - 2017-11-27 21:55:14.518; [ ]
org.apache.solr.search.SolrIndexSearcher; Opening
[Searcher@26ed891f[test_shard1_replica_n1] main]
INFO - 2017-11-27 21:55:14.521; [ ]
org.apache.solr.core.QuerySenderListener; QuerySenderListener sending requests
to Searcher@26ed891f[test_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
INFO - 2017-11-27 21:55:14.521; [ ]
org.apache.solr.core.QuerySenderListener; QuerySenderListener done.
INFO - 2017-11-27 21:55:14.522; [ ] org.apache.solr.core.SolrCore;
[test_shard1_replica_n1] Registered new searcher
Searcher@26ed891f[test_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
INFO - 2017-11-27 21:55:14.614; [ ]
org.apache.solr.handler.SolrConfigHandler$Command; I already have the expected
version 0 of config
INFO - 2017-11-27 21:55:14.614; [ ]
org.apache.solr.handler.SolrConfigHandler$Command; isStale false ,
resourceloader org.apache.solr.cloud.ZkSolrResourceLoader
INFO - 2017-11-27 21:55:14.615; [ ] org.apache.solr.core.SolrCore;
[test_shard1_replica_n1] webapp=/solr path=/config/znodeVersion
params={overlay=0&wt=javabin&version=2} status=0 QTime=1
INFO - 2017-11-27 21:55:14.618; [ ]
org.apache.solr.handler.SolrConfigHandler; Took 442.0ms to set the property
overlay to be of version 0 for collection test
INFO - 2017-11-27 21:55:14.618; [ ] org.apache.solr.core.SolrCore;
[test_shard1_replica_n1] webapp=/solr path=/config
params={wt=javabin&version=2} status=0 QTime=494
INFO - 2017-11-27 21:55:14.619; [ ] org.apache.solr.core.SolrCore;
[test_shard1_replica_n1] CLOSING SolrCore
org.apache.solr.core.SolrCore@7d3d636d
INFO - 2017-11-27 21:55:14.619; [ ]
org.apache.solr.metrics.SolrMetricManager; Closing metric reporters for
registry=solr.core.test.shard1.replica_n1, tag=2101175149
INFO - 2017-11-27 21:55:14.619; [ ]
org.apache.solr.metrics.SolrMetricManager; Closing metric reporters for
registry=solr.collection.test.shard1.leader, tag=2101175149
{code}
I'll comment on the Jira with what all lines should we potentially change to
DEBUG
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
