Индекс с возможностью поиска блокируется при обновлении вручную (LockObtainFailedException)

Question

У нас есть проект Grails, который работает за балансировщиком нагрузки. На сервере запущено три экземпляра приложения Grails (с использованием отдельных экземпляров Tomcat). Каждый экземпляр имеет свой собственный поисковый индекс. Поскольку индексы являются отдельными, автоматического обновления недостаточно для поддержания согласованности индекса между экземплярами приложения. Из-за этого мы отключили зеркалирование индекса с возможностью поиска и обновления индекса выполняются вручную в запланированном задании кварца. Согласно нашему пониманию, никакая другая часть приложения не должна изменять индекс.

Кварцевое задание выполняется один раз в минуту, и оно проверяет из базы данных, какие строки были обновлены приложением, и повторно индексирует эти объекты. Задание также проверяет, выполняется ли уже то же задание, поэтому не выполняет параллельную индексацию. Приложение запускается нормально в течение нескольких часов после запуска, а затем внезапно, когда запускается задание, возникает исключение LockObtainFailedException:

22.10.2012 11:20:40 [xxxx.ReindexJob] ОШИБКА Не удалось обновить поисковый индекс, класс org.compass.core.engine.SearchEngineException: не удалось открыть средство записи для подиндекса [product]; вложенное исключение: org.apache.lucene.store.LockObtainFailedException: время ожидания блокировки истекло: SimpleFSLock@/home/xxx/tomcat/searchable-index/index/product/lucene-a7bbc72a49512284f5ac54f5d7d32849w

Согласно журналу в последний раз, когда задание было выполнено, повторное индексирование было выполнено без ошибок, и задание было успешно завершено. Тем не менее, на этот раз операция переиндексации выдает исключение блокировки, как если бы предыдущая операция была незавершенной, а блокировка не была снята. Блокировка не будет снята, пока приложение не будет перезапущено.

Мы попытались решить проблему, открыв заблокированный индекс вручную, в результате чего в журнал выводилась следующая ошибка:

22.10.2012 11:21:30 [manager.IndexWritersManager] ОШИБКА Недопустимое состояние, отметка средства записи индекса как открытого, в то время как другое помечено как открытое для подиндекса [product]

После этого работа, кажется, работает правильно и больше не застревает в заблокированном состоянии. Однако это приводит к тому, что приложение постоянно использует 100 % ресурсов процессора. Ниже приведена сокращенная версия кварцевого кода работы.

Любая помощь будет оценена, чтобы решить проблему, спасибо заранее.

class ReindexJob {

def compass
...

static Calendar lastIndexed

static triggers = {
    // Every day every minute (at xx:xx:30), start delay 2 min
    // cronExpression:                           "s  m h D M W [Y]"
    cron name: "ReindexTrigger", cronExpression: "30 * * * * ?", startDelay: 120000
}

def execute() {
    if (ConcurrencyHelper.isLocked(ConcurrencyHelper.Locks.LUCENE_INDEX)) {
        log.error("Search index has been locked, not doing anything.")
        return
    }

    try {
        boolean acquiredLock = ConcurrencyHelper.lock(ConcurrencyHelper.Locks.LUCENE_INDEX, "ReindexJob")
        if (!acquiredLock) {
            log.warn("Could not lock search index, not doing anything.")
            return
        }

        Calendar reindexDate = lastIndexed
        Calendar newReindexDate = Calendar.instance
        if (!reindexDate) {
            reindexDate = Calendar.instance
            reindexDate.add(Calendar.MINUTE, -3)
            lastIndexed = reindexDate
        }

        log.debug("+++ Starting ReindexJob, last indexed ${TextHelper.formatDate("yyyy-MM-dd HH:mm:ss", reindexDate.time)} +++")
        Long start = System.currentTimeMillis()

        String reindexMessage = ""

        // Retrieve the ids of products that have been modified since the job last ran
        String productQuery = "select p.id from Product ..."
        List<Long> productIds = Product.executeQuery(productQuery, ["lastIndexedDate": reindexDate.time, "lastIndexedCalendar": reindexDate])

        if (productIds) {
            reindexMessage += "Found ${productIds.size()} product(s) to reindex. "

            final int BATCH_SIZE = 10
            Long time = TimeHelper.timer {
                for (int inserted = 0; inserted < productIds.size(); inserted += BATCH_SIZE) {
                    log.debug("Indexing from ${inserted + 1} to ${Math.min(inserted + BATCH_SIZE, productIds.size())}: ${productIds.subList(inserted, Math.min(inserted + BATCH_SIZE, productIds.size()))}")
                    Product.reindex(productIds.subList(inserted, Math.min(inserted + BATCH_SIZE, productIds.size())))
                    Thread.sleep(250)
                }
            }

            reindexMessage += " (${time / 1000} s). "
        } else {
            reindexMessage += "No products to reindex. "
        }

        log.debug(reindexMessage)

        // Re-index brands
        Brand.reindex()

        lastIndexed = newReindexDate

        log.debug("+++ Finished ReindexJob (${(System.currentTimeMillis() - start) / 1000} s) +++")
    } catch (Exception e) {
        log.error("Could not update searchable index, ${e.class}: ${e.message}")
        if (e instanceof org.apache.lucene.store.LockObtainFailedException || e instanceof org.compass.core.engine.SearchEngineException) {
            log.info("This is a Lucene index locking exception.")
            for (String subIndex in compass.searchEngineIndexManager.getSubIndexes()) {
                if (compass.searchEngineIndexManager.isLocked(subIndex)) {
                    log.info("Releasing Lucene index lock for sub index ${subIndex}")
                    compass.searchEngineIndexManager.releaseLock(subIndex)
                }
            }
        }
    } finally {
        ConcurrencyHelper.unlock(ConcurrencyHelper.Locks.LUCENE_INDEX, "ReindexJob")
    }
}
}

Судя по образцам процессоров JMX, Compass делает некоторые планы за кулисами. Из 1-минутных выборок ЦП кажется, что при обычном сравнении и 100 % -ых экземплярах ЦП мало что отличается:

• org.apache.lucene.index.IndexWriter.doWait () использует большую часть процессорного времени.
• Compass Scheduled Executor Thread отображается в списке потоков, в обычной ситуации такого не было.
• Один поток Compass Executor выполняет commitMerge, в нормальной ситуации ни один из этих потоков не делал commitMerge.

Answer 1

Вы можете попробовать увеличить настройку 'compass.transaction.lockTimeout'. По умолчанию установлено значение 10 (секунд).

Другой вариант - отключить параллелизм в Compass и сделать его синхронным. Это контролируется с помощью параметра 'compass.transaction.processor.read_committed.concurrentOperations': 'false'. Возможно, вам также придется установить 'compass.transaction.processor' в 'read_committed'

Вот настройки компаса, которые мы используем в настоящее время:

compassSettings = [
'compass.engine.optimizer.schedule.period': '300',
'compass.engine.mergeFactor':'1000',
'compass.engine.maxBufferedDocs':'1000',
'compass.engine.ramBufferSize': '128',
'compass.engine.useCompoundFile': 'false',
'compass.transaction.processor': 'read_committed',
'compass.transaction.processor.read_committed.concurrentOperations': 'false',
'compass.transaction.lockTimeout': '30',
'compass.transaction.lockPollInterval': '500',
'compass.transaction.readCommitted.translog.connection': 'ram://'
]

Это параллелизм отключен. Вы можете сделать это асинхронным, изменив для параметра 'compass.transaction.processor.read_committed.concurrentOperations' значение 'true'. (или удаляя запись).

Ссылка на конфигурацию компаса: http://static.compassframework.org/docs/latest/core-configuration.html

Документация по параллелизму процессора read_committed: http://www.compass-project.org/docs/latest/reference/html/core-searchengine.html

Если вы хотите сохранить асинхронные операции, вы также можете контролировать количество потоков, которые он использует. Использование параметра compass.transaction.processor.read_committed.concurrencyLevel=1 разрешает асинхронные операции, но использует только один поток (по умолчанию 5 потоков). Существуют также настройки compass.transaction.processor.read_committed.backlog и compass.transaction.processor.read_committed.addTimeout.

Надеюсь, это поможет.