You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by "lvchuanwen (JIRA)" <ji...@apache.org> on 2016/03/19 06:13:33 UTC

[jira] [Commented] (SOLR-8335) HdfsLockFactory does not allow core to come up after a node was killed

    [ https://issues.apache.org/jira/browse/SOLR-8335?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15202567#comment-15202567 ] 

lvchuanwen commented on SOLR-8335:
----------------------------------

hi ,
On solr 4.10.3,I have occasionally encountered this problem, when the Solr has just started, why there will be a lock already exist? Is bug?Was it a bug?
{code:title=Directory.java|borderStyle=solid}
  @Override
  public String toString() {
    return getClass().getSimpleName() + '@' + Integer.toHexString(hashCode()) + " lockFactory=" + getLockFactory();
  }
{code}
LOG as follow:

{code:xml}
2016-03-16 15:51:31,327 INFO org.apache.solr.servlet.SolrHadoopAuthenticationFilter: Connecting to ZooKeeper without authentication
2016-03-16 15:51:31,434 INFO org.apache.curator.framework.imps.CuratorFrameworkImpl: Starting
2016-03-16 15:51:31,445 INFO org.apache.zookeeper.ZooKeeper: Client environment:zookeeper.version=3.4.5-test5.4.2--1, built on 05/19/2015 23:53 GMT
2016-03-16 15:51:31,445 INFO org.apache.zookeeper.ZooKeeper: Client environment:host.name=Impala03
2016-03-16 15:51:31,445 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.version=1.7.0_55
2016-03-16 15:51:31,445 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.vendor=Oracle Corporation
2016-03-16 15:51:31,445 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.home=/usr/java/jdk/jre
2016-03-16 15:51:31,445 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.class.path=/home/mr/tomcat/bin/bootstrap.jar
2016-03-16 15:51:31,445 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.library.path=/home/hdfs/hdfs/lib/native/Linux-amd64-64/
2016-03-16 15:51:31,445 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.io.tmpdir=/var/lib/solr/
2016-03-16 15:51:31,445 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.compiler=<NA>
2016-03-16 15:51:31,446 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.name=Linux
2016-03-16 15:51:31,446 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.arch=amd64
2016-03-16 15:51:31,446 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.version=3.0.13-0.27-default
2016-03-16 15:51:31,446 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.name=mr
2016-03-16 15:51:31,446 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.home=/home/mr
2016-03-16 15:51:31,446 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.dir=/home/mr/solr/bin
2016-03-16 15:51:31,447 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=Impala04:2181,Impala02:2181,Impala03:2181 sessionTimeout=60000 watcher=org.apache.curator.ConnectionState@2590f83a
2016-03-16 15:51:31,472 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server Impala03/10.233.85.238:2181. Will not attempt to authenticate using SASL (unknown error)
2016-03-16 15:51:31,483 INFO org.apache.zookeeper.ClientCnxn: Socket connection established, initiating session, client: /10.233.85.238:42992, server: Impala03/10.233.85.238:2181
2016-03-16 15:51:31,492 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server Impala03/10.233.85.238:2181, sessionid = 0x35379cb0b604e1f, negotiated timeout = 60000
2016-03-16 15:51:31,499 INFO org.apache.curator.framework.state.ConnectionStateManager: State change: CONNECTED
2016-03-16 15:51:32,533 INFO org.apache.hadoop.security.authentication.util.ZKSignerSecretProvider: The secret znode already exists, retrieving data
2016-03-16 15:51:33,392 INFO org.apache.hadoop.security.token.delegation.AbstractDelegationTokenSecretManager: Updating the current master key for generating delegation tokens
2016-03-16 15:51:33,420 INFO org.apache.hadoop.security.token.delegation.AbstractDelegationTokenSecretManager: Starting expired delegation token remover thread, tokenRemoverScanInterval=60 min(s)
2016-03-16 15:51:33,536 INFO org.apache.hadoop.security.token.delegation.AbstractDelegationTokenSecretManager: Updating the current master key for generating delegation tokens
2016-03-16 15:51:33,570 INFO org.apache.solr.servlet.SolrDispatchFilter: SolrDispatchFilter.init()
2016-03-16 15:51:33,588 INFO org.apache.solr.core.SolrResourceLoader: No /solr/home in JNDI
2016-03-16 15:51:33,588 INFO org.apache.solr.core.SolrResourceLoader: using system property solr.solr.home: /var/lib/solr/
2016-03-16 15:51:33,588 INFO org.apache.solr.core.SolrResourceLoader: new SolrResourceLoader for directory: '/var/lib/solr/'
2016-03-16 15:51:33,767 INFO org.apache.solr.servlet.SolrDispatchFilter: Trying to read solr.xml from Impala04:2181,Impala02:2181,Impala03:2181/solr
2016-03-16 15:51:33,781 INFO org.apache.solr.common.cloud.SolrZkClient: Using default ZkCredentialsProvider
2016-03-16 15:51:33,786 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=Impala04:2181,Impala02:2181,Impala03:2181/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@5943d900
2016-03-16 15:51:33,787 INFO org.apache.solr.common.cloud.ConnectionManager: Waiting for client to connect to ZooKeeper
2016-03-16 15:51:33,787 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server Impala03/10.233.85.238:2181. Will not attempt to authenticate using SASL (unknown error)
2016-03-16 15:51:33,788 INFO org.apache.zookeeper.ClientCnxn: Socket connection established, initiating session, client: /10.233.85.238:42993, server: Impala03/10.233.85.238:2181
2016-03-16 15:51:33,790 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server Impala03/10.233.85.238:2181, sessionid = 0x35379cb0b604e20, negotiated timeout = 30000
2016-03-16 15:51:33,790 INFO org.apache.solr.common.cloud.ConnectionManager: Watcher org.apache.solr.common.cloud.ConnectionManager@5943d900 name:ZooKeeperConnection Watcher:Impala04:2181,Impala02:2181,Impala03:2181/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
2016-03-16 15:51:33,790 INFO org.apache.solr.common.cloud.ConnectionManager: Client is connected to ZooKeeper
2016-03-16 15:51:33,790 INFO org.apache.solr.common.cloud.SolrZkClient: Using default ZkACLProvider
2016-03-16 15:51:33,878 INFO org.apache.solr.core.CoresLocator: Config-defined core root directory: /var/lib/solr
2016-03-16 15:51:33,880 INFO org.apache.zookeeper.ZooKeeper: Session: 0x35379cb0b604e20 closed
2016-03-16 15:51:33,880 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
2016-03-16 15:51:33,887 INFO org.apache.solr.core.CoreContainer: New CoreContainer 1881284549
2016-03-16 15:51:33,887 INFO org.apache.solr.core.CoreContainer: Loading cores into CoreContainer [instanceDir=/var/lib/solr/]
2016-03-16 15:51:33,887 INFO org.apache.solr.core.CoreContainer: Begin register HeartBeat
2016-03-16 15:51:33,905 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting socketTimeout to: 0
2016-03-16 15:51:33,906 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting urlScheme to: null
2016-03-16 15:51:33,906 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting connTimeout to: 0
2016-03-16 15:51:33,906 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting maxConnectionsPerHost to: 20
2016-03-16 15:51:33,906 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting corePoolSize to: 0
2016-03-16 15:51:33,906 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting maximumPoolSize to: 2147483647
2016-03-16 15:51:33,906 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting maxThreadIdleTime to: 5
2016-03-16 15:51:33,906 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting sizeOfQueue to: -1
2016-03-16 15:51:33,906 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting fairnessPolicy to: false
2016-03-16 15:51:33,906 INFO org.apache.solr.handler.component.HttpShardHandlerFactory: Setting useRetries to: false
2016-03-16 15:51:34,022 INFO org.apache.solr.logging.LogWatcher: SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
2016-03-16 15:51:34,022 INFO org.apache.solr.logging.LogWatcher: Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
2016-03-16 15:51:34,023 INFO org.apache.solr.core.CoreContainer: Host Name: Impala03
2016-03-16 15:51:34,024 INFO org.apache.solr.core.ZkContainer: Zookeeper client=Impala04:2181,Impala02:2181,Impala03:2181/solr
2016-03-16 15:51:34,031 INFO org.apache.solr.cloud.ZkController: zkHost includes chroot
2016-03-16 15:51:34,032 INFO org.apache.solr.common.cloud.SolrZkClient: Using default ZkCredentialsProvider
2016-03-16 15:51:34,032 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=Impala04:2181,Impala02:2181,Impala03:2181 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@23c93725
2016-03-16 15:51:34,032 INFO org.apache.solr.common.cloud.ConnectionManager: Waiting for client to connect to ZooKeeper
2016-03-16 15:51:34,033 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server Impala02/10.233.85.237:2181. Will not attempt to authenticate using SASL (unknown error)
2016-03-16 15:51:34,034 INFO org.apache.zookeeper.ClientCnxn: Socket connection established, initiating session, client: /10.233.85.238:45311, server: Impala02/10.233.85.237:2181
2016-03-16 15:51:34,035 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server Impala02/10.233.85.237:2181, sessionid = 0x25379cb085d4f3b, negotiated timeout = 60000
2016-03-16 15:51:34,036 INFO org.apache.solr.common.cloud.ConnectionManager: Watcher org.apache.solr.common.cloud.ConnectionManager@23c93725 name:ZooKeeperConnection Watcher:Impala04:2181,Impala02:2181,Impala03:2181 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
2016-03-16 15:51:34,036 INFO org.apache.solr.common.cloud.ConnectionManager: Client is connected to ZooKeeper
2016-03-16 15:51:34,036 INFO org.apache.solr.common.cloud.SolrZkClient: Using default ZkACLProvider
2016-03-16 15:51:34,038 INFO org.apache.zookeeper.ZooKeeper: Session: 0x25379cb085d4f3b closed
2016-03-16 15:51:34,039 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
2016-03-16 15:51:34,041 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=Impala04:2181,Impala02:2181,Impala03:2181/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@3ef17aa1
2016-03-16 15:51:34,041 INFO org.apache.solr.common.cloud.ConnectionManager: Waiting for client to connect to ZooKeeper
2016-03-16 15:51:34,042 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server Impala04/10.233.85.239:2181. Will not attempt to authenticate using SASL (unknown error)
2016-03-16 15:51:34,042 INFO org.apache.zookeeper.ClientCnxn: Socket connection established, initiating session, client: /10.233.85.238:30675, server: Impala04/10.233.85.239:2181
2016-03-16 15:51:34,045 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server Impala04/10.233.85.239:2181, sessionid = 0x15379cb082a4e11, negotiated timeout = 30000
2016-03-16 15:51:34,045 INFO org.apache.solr.common.cloud.ConnectionManager: Watcher org.apache.solr.common.cloud.ConnectionManager@3ef17aa1 name:ZooKeeperConnection Watcher:Impala04:2181,Impala02:2181,Impala03:2181/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
2016-03-16 15:51:34,045 INFO org.apache.solr.common.cloud.ConnectionManager: Client is connected to ZooKeeper
2016-03-16 15:51:34,076 INFO org.apache.solr.common.cloud.ZkStateReader: Updating cluster state from ZooKeeper... 
2016-03-16 15:51:34,114 INFO org.apache.solr.common.cloud.ZkStateReader: A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
2016-03-16 15:51:36,102 INFO org.apache.solr.cloud.ZkController: Register node as live in ZooKeeper:/live_nodes/Impala03:8983_solr
2016-03-16 15:51:36,107 INFO org.apache.solr.common.cloud.SolrZkClient: makePath: /live_nodes/Impala03:8983_solr
2016-03-16 15:51:36,113 INFO org.apache.solr.cloud.Overseer: Overseer (id=null) closing
2016-03-16 15:51:36,139 INFO org.apache.solr.core.CoresLocator: Looking for core definitions underneath /var/lib/solr
2016-03-16 15:51:36,150 INFO org.apache.solr.core.CoresLocator: Found core TESTX_shard2_replica1 in /var/lib/solr/TESTX_shard2_replica1/
2016-03-16 15:51:36,151 INFO org.apache.solr.core.CoresLocator: Found 1 core definitions
2016-03-16 15:51:36,157 INFO org.apache.solr.cloud.ZkController: publishing core=TESTX_shard2_replica1 state=down collection=TESTX
2016-03-16 15:51:36,157 INFO org.apache.solr.cloud.ZkController: numShards not found on descriptor - reading it from system property
2016-03-16 15:51:36,161 INFO org.apache.solr.cloud.ZkController: waiting to find shard id in clusterstate for TESTX_shard2_replica1
2016-03-16 15:51:36,161 INFO org.apache.solr.cloud.ZkController: Check for collection zkNode:TESTX
2016-03-16 15:51:36,162 INFO org.apache.solr.cloud.ZkController: Collection zkNode exists
2016-03-16 15:51:36,162 INFO org.apache.solr.common.cloud.ZkStateReader: Load collection config from:/collections/TESTX
2016-03-16 15:51:36,164 INFO org.apache.solr.common.cloud.ZkStateReader: path=/collections/TESTX configName=TESTX specified config exists in ZooKeeper
2016-03-16 15:51:36,164 INFO org.apache.solr.core.SolrResourceLoader: new SolrResourceLoader for directory: '/var/lib/solr/TESTX_shard2_replica1/'
2016-03-16 15:51:36,172 INFO org.apache.solr.common.cloud.ZkStateReader: A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
2016-03-16 15:51:36,242 INFO org.apache.solr.core.SolrConfig: Adding specified lib dirs to ClassLoader
2016-03-16 15:51:36,243 WARN org.apache.solr.core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /var/lib/solr/TESTX_shard2_replica1/../../../contrib/extraction/lib).
2016-03-16 15:51:36,243 WARN org.apache.solr.core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /var/lib/solr/TESTX_shard2_replica1/../../../dist).
2016-03-16 15:51:36,243 WARN org.apache.solr.core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /var/lib/solr/TESTX_shard2_replica1/../../../contrib/clustering/lib).
2016-03-16 15:51:36,243 WARN org.apache.solr.core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /var/lib/solr/TESTX_shard2_replica1/../../../dist).
2016-03-16 15:51:36,243 WARN org.apache.solr.core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /var/lib/solr/TESTX_shard2_replica1/../../../contrib/langid/lib).
2016-03-16 15:51:36,243 WARN org.apache.solr.core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /var/lib/solr/TESTX_shard2_replica1/../../../dist).
2016-03-16 15:51:36,243 WARN org.apache.solr.core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /var/lib/solr/TESTX_shard2_replica1/../../../contrib/velocity/lib).
2016-03-16 15:51:36,243 WARN org.apache.solr.core.SolrResourceLoader: Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /var/lib/solr/TESTX_shard2_replica1/../../../dist).
2016-03-16 15:51:36,374 INFO org.apache.solr.update.SolrIndexConfig: IndexWriter infoStream solr logging is enabled
2016-03-16 15:51:36,382 INFO org.apache.solr.core.SolrConfig: Using Lucene MatchVersion: 4.10.3
2016-03-16 15:51:36,493 INFO org.apache.solr.core.Config: Loaded SolrConfig: solrconfig.xml
2016-03-16 15:51:36,505 INFO org.apache.solr.schema.IndexSchema: Reading Solr Schema from /configs/TESTX/managed-schema
2016-03-16 15:51:36,571 INFO org.apache.solr.schema.IndexSchema: [TESTX_shard2_replica1] Schema name=example-schemaless
2016-03-16 15:51:36,711 WARN org.apache.solr.core.SolrResourceLoader: Solr loaded a deprecated plugin/analysis class [solr.DateField]. Please consult documentation how to replace it accordingly.
2016-03-16 15:51:36,716 WARN org.apache.solr.core.SolrResourceLoader: Solr loaded a deprecated plugin/analysis class [solr.DoubleField]. Please consult documentation how to replace it accordingly.
2016-03-16 15:51:36,721 WARN org.apache.solr.core.SolrResourceLoader: Solr loaded a deprecated plugin/analysis class [solr.FloatField]. Please consult documentation how to replace it accordingly.
2016-03-16 15:51:36,731 WARN org.apache.solr.core.SolrResourceLoader: Solr loaded a deprecated plugin/analysis class [solr.IntField]. Please consult documentation how to replace it accordingly.
2016-03-16 15:51:36,735 WARN org.apache.solr.core.SolrResourceLoader: Solr loaded a deprecated plugin/analysis class [solr.LongField]. Please consult documentation how to replace it accordingly.
2016-03-16 15:51:37,022 WARN org.apache.solr.core.SolrResourceLoader: Solr loaded a deprecated plugin/analysis class [solr.ThaiWordFilterFactory]. Please consult documentation how to replace it accordingly.
2016-03-16 15:51:37,085 INFO org.apache.solr.schema.IndexSchema: unique key field: id
2016-03-16 15:51:37,087 INFO org.apache.solr.schema.FileExchangeRateProvider: Reloading exchange rates from file currency.xml
2016-03-16 15:51:37,096 INFO org.apache.solr.schema.FileExchangeRateProvider: Reloading exchange rates from file currency.xml
2016-03-16 15:51:37,370 INFO org.apache.solr.core.CoreContainer: Creating SolrCore 'TESTX_shard2_replica1' using configuration from collection TESTX
2016-03-16 15:51:37,400 INFO org.apache.solr.core.SolrCore: org.apache.solr.core.HdfsDirectoryFactory
2016-03-16 15:51:37,410 INFO org.apache.solr.core.HdfsDirectoryFactory: solr.hdfs.home=hdfs://LV//solr
2016-03-16 15:51:37,410 INFO org.apache.solr.core.HdfsDirectoryFactory: Solr Kerberos Authentication disabled
2016-03-16 15:51:37,410 INFO org.apache.solr.core.SolrCore: [TESTX_shard2_replica1] Opening new SolrCore at /var/lib/solr/TESTX_shard2_replica1/, dataDir=hdfs://LV//solr/TESTX/core_node1/data/
2016-03-16 15:51:37,412 INFO org.apache.solr.core.JmxMonitoredMap: JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cae38bd
2016-03-16 15:51:37,444 INFO org.apache.solr.core.SolrCore: [TESTX_shard2_replica1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
2016-03-16 15:51:37,444 INFO org.apache.solr.core.SolrCore: [TESTX_shard2_replica1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
2016-03-16 15:51:37,455 INFO org.apache.solr.core.HdfsDirectoryFactory: creating directory factory for path hdfs://LV//solr/TESTX/core_node1/data
2016-03-16 15:51:38,259 INFO org.apache.solr.core.CachingDirectoryFactory: return new directory for hdfs://LV//solr/TESTX/core_node1/data
2016-03-16 15:51:38,262 INFO org.apache.solr.core.SolrCore: New index directory detected: old=null new=hdfs://LV//solr/TESTX/core_node1/data/index/
2016-03-16 15:51:38,297 INFO org.apache.solr.core.HdfsDirectoryFactory: creating directory factory for path hdfs://LV//solr/TESTX/core_node1/data/index
2016-03-16 15:51:38,327 INFO org.apache.solr.core.HdfsDirectoryFactory: Number of slabs of block cache [1] with direct memory allocation set to [true]
2016-03-16 15:51:38,327 INFO org.apache.solr.core.HdfsDirectoryFactory: Block cache target memory usage, slab size of [134217728] will allocate [1] slabs and use ~[134217728] bytes
2016-03-16 15:51:38,327 INFO org.apache.solr.core.HdfsDirectoryFactory: Creating new global HDFS BlockCache
2016-03-16 15:51:38,381 INFO org.apache.solr.store.blockcache.BlockDirectory: Block cache on write is disabled
2016-03-16 15:51:38,381 INFO org.apache.solr.core.CachingDirectoryFactory: return new directory for hdfs://LV//solr/TESTX/core_node1/data/index
2016-03-16 15:51:38,395 ERROR org.apache.solr.core.SolrCore: [TESTX_shard2_replica1] Solr index directory 'hdfs://LV//solr/TESTX/core_node1/data/index/' is locked.  Throwing exception
2016-03-16 15:51:38,395 INFO org.apache.solr.core.SolrCore: [TESTX_shard2_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@cadc90b
2016-03-16 15:51:38,395 INFO org.apache.solr.update.SolrCoreState: Closing SolrCoreState
2016-03-16 15:51:38,395 INFO org.apache.solr.update.DefaultSolrCoreState: SolrCoreState ref count has reached 0 - closing IndexWriter
2016-03-16 15:51:38,395 INFO org.apache.solr.core.SolrCore: [TESTX_shard2_replica1] Closing main searcher on request.
2016-03-16 15:51:38,398 INFO org.apache.solr.core.CachingDirectoryFactory: Closing HdfsDirectoryFactory - 2 directories currently being tracked
2016-03-16 15:51:38,398 INFO org.apache.solr.core.CachingDirectoryFactory: looking to close hdfs://LV//solr/TESTX/core_node1/data [CachedDir<<refCount=0;path=hdfs://LV//solr/TESTX/core_node1/data;done=false>>]
2016-03-16 15:51:38,398 INFO org.apache.solr.core.CachingDirectoryFactory: Closing directory: hdfs://LV//solr/TESTX/core_node1/data
2016-03-16 15:51:38,398 INFO org.apache.solr.store.hdfs.HdfsDirectory: Closing hdfs directory hdfs://LV/solr/TESTX/core_node1/data
2016-03-16 15:51:38,398 INFO org.apache.solr.core.CachingDirectoryFactory: looking to close hdfs://LV//solr/TESTX/core_node1/data/index [CachedDir<<refCount=0;path=hdfs://LV//solr/TESTX/core_node1/data/index;done=false>>]
2016-03-16 15:51:38,398 INFO org.apache.solr.core.CachingDirectoryFactory: Closing directory: hdfs://LV//solr/TESTX/core_node1/data/index
2016-03-16 15:51:38,519 INFO org.apache.solr.store.hdfs.HdfsDirectory: Closing hdfs directory hdfs://LV/solr/TESTX/core_node1/data/index
2016-03-16 15:51:38,622 ERROR org.apache.solr.core.CoreContainer: Error creating core [TESTX_shard2_replica1]: Index locked for write for core TESTX_shard2_replica1
org.apache.solr.common.SolrException: Index locked for write for core TESTX_shard2_replica1
	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:884)
	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:657)
	at org.apache.solr.core.CoreContainer.create(CoreContainer.java:496)
	at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:260)
	at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:254)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.lucene.store.LockObtainFailedException: Index locked for write for core TESTX_shard2_replica1
	at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:519)
	at org.apache.solr.core.SolrCore.<init>(SolrCore.java:788)
	... 8 more
2016-03-16 15:51:38,627 INFO org.apache.solr.servlet.SolrDispatchFilter: user.dir=/home/mr/solr/bin
2016-03-16 15:51:38,627 INFO org.apache.solr.servlet.SolrDispatchFilter: SolrDispatchFilter.init() done

{code}


> HdfsLockFactory does not allow core to come up after a node was killed
> ----------------------------------------------------------------------
>
>                 Key: SOLR-8335
>                 URL: https://issues.apache.org/jira/browse/SOLR-8335
>             Project: Solr
>          Issue Type: Bug
>    Affects Versions: 5.0, 5.1, 5.2, 5.2.1, 5.3, 5.3.1
>            Reporter: Varun Thacker
>
> When using HdfsLockFactory if a node gets killed instead of a graceful shutdown the write.lock file remains in HDFS . The next time you start the node the core doesn't load up because of LockObtainFailedException .
> I was able to reproduce this in all 5.x versions of Solr . The problem wasn't there when I tested it in 4.10.4
> Steps to reproduce this on 5.x
> 1. Create directory in HDFS : {{bin/hdfs dfs -mkdir /solr}}
> 2. Start Solr: {{bin/solr start -Dsolr.directoryFactory=HdfsDirectoryFactory -Dsolr.lock.type=hdfs -Dsolr.data.dir=hdfs://localhost:9000/solr -Dsolr.updatelog=hdfs://localhost:9000/solr}}
> 3. Create core: {{./bin/solr create -c test -n data_driven}}
> 4. Kill solr
> 5. The lock file is there in HDFS and is called {{write.lock}}
> 6. Start Solr again and you get a stack trace like this:
> {code}
> 2015-11-23 13:28:04.287 ERROR (coreLoadExecutor-6-thread-1) [   x:test] o.a.s.c.CoreContainer Error creating core [test]: Index locked for write for core 'test'. Solr now longer supports forceful unlocking via 'unlockOnStartup'. Please verify locks manually!
> org.apache.solr.common.SolrException: Index locked for write for core 'test'. Solr now longer supports forceful unlocking via 'unlockOnStartup'. Please verify locks manually!
>         at org.apache.solr.core.SolrCore.<init>(SolrCore.java:820)
>         at org.apache.solr.core.SolrCore.<init>(SolrCore.java:659)
>         at org.apache.solr.core.CoreContainer.create(CoreContainer.java:723)
>         at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:443)
>         at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:434)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>         at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:210)
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>         at java.lang.Thread.run(Thread.java:745)
> Caused by: org.apache.lucene.store.LockObtainFailedException: Index locked for write for core 'test'. Solr now longer supports forceful unlocking via 'unlockOnStartup'. Please verify locks manually!
>         at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:528)
>         at org.apache.solr.core.SolrCore.<init>(SolrCore.java:761)
>         ... 9 more
> 2015-11-23 13:28:04.289 ERROR (coreContainerWorkExecutor-2-thread-1) [   ] o.a.s.c.CoreContainer Error waiting for SolrCore to be created
> java.util.concurrent.ExecutionException: org.apache.solr.common.SolrException: Unable to create core [test]
>         at java.util.concurrent.FutureTask.report(FutureTask.java:122)
>         at java.util.concurrent.FutureTask.get(FutureTask.java:192)
>         at org.apache.solr.core.CoreContainer$2.run(CoreContainer.java:472)
>         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>         at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:210)
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>         at java.lang.Thread.run(Thread.java:745)
> Caused by: org.apache.solr.common.SolrException: Unable to create core [test]
>         at org.apache.solr.core.CoreContainer.create(CoreContainer.java:737)
>         at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:443)
>         at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:434)
>         ... 5 more
> Caused by: org.apache.solr.common.SolrException: Index locked for write for core 'test'. Solr now longer supports forceful unlocking via 'unlockOnStartup'. Please verify locks manually!
>         at org.apache.solr.core.SolrCore.<init>(SolrCore.java:820)
>         at org.apache.solr.core.SolrCore.<init>(SolrCore.java:659)
>         at org.apache.solr.core.CoreContainer.create(CoreContainer.java:723)
>         ... 7 more
> Caused by: org.apache.lucene.store.LockObtainFailedException: Index locked for write for core 'test'. Solr now longer supports forceful unlocking via 'unlockOnStartup'. Please verify locks manually!
>         at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:528)
>         at org.apache.solr.core.SolrCore.<init>(SolrCore.java:761)
>         ... 9 more
> {code}
> In 4.10.4 I saw these two differences
> 1. The lock file name was different . It's something like : {{/solr/index/HdfsDirectory@46ad6bd3 lockFactory=org.apache.solr.store.hdfs.HdfsLockFactory@4b44b5f6-write.lock}}
> 2. When the node is started again after it was killed , it loaded up the core just fine but there were two lock files in hdfs now . 4b44b5f6-write.lock is the latest one
> {code}
> /solr/index/HdfsDirectory@46ad6bd3 lockFactory=org.apache.solr.store.hdfs.HdfsLockFactory@4b44b5f6-write.lock
> /solr/index/HdfsDirectory@52959724 lockFactory=org.apache.solr.store.hdfs.HdfsLockFactory@9d59d3f-write.lock
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org