Исключение MongoTransactionException: ошибка запроса с кодом ошибки 251

#mongodb #spring-data-mongodb

#mongodb #spring-data-mongodb

Вопрос:

Столкнулся с этим исключением Mongo при запросе документа в транзакции только с определенным идентификатором (все остальные идентификаторы в порядке):

 Exception occured: org.springframework.data.mongodb.MongoTransactionException: 
Query failed with error code 251 and error message 
'Given transaction number 1 does not match any in-progress transactions. The active transaction number is -1' on server mongo-1:27017; 
nested exception is com.mongodb.MongoQueryException: 
Query failed with error code 251 and error message 
'Given transaction number 1 does not match any in-progress transactions. The active transaction number is -1' on server mongo-1:27017 
at org.springframework.data.mongodb.core.MongoExceptionTranslator.translateExceptionIfPossible(MongoExceptionTranslator.java:136) 
at org.springframework.data.mongodb.core.MongoTemplate.potentiallyConvertRuntimeException(MongoTemplate.java:2902) 
at org.springframework.data.mongodb.core.MongoTemplate.executeFindMultiInternal(MongoTemplate.java:2810) 
at org.springframework.data.mongodb.core.MongoTemplate.doFind(MongoTemplate.java:2555) 
at org.springframework.data.mongodb.core.ExecutableFindOperationSupport$ExecutableFindSupport.doFind(ExecutableFindOperationSupport.java:216) 
at org.springframework.data.mongodb.core.ExecutableFindOperationSupport$ExecutableFindSupport.oneValue(ExecutableFindOperationSupport.java:128) 
at org.springframework.data.mongodb.repository.query.AbstractMongoQuery.lambda$getExecution$4(AbstractMongoQuery.java:153) 
at org.springframework.data.mongodb.repository.query.AbstractMongoQuery.doExecute(AbstractMongoQuery.java:126) 
at org.springframework.data.mongodb.repository.query.AbstractMongoQuery.execute(AbstractMongoQuery.java:101) 
at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:618) 
  

MongoDB является разделенным кластером, и аналогичное действие выполняется для полностью аналогичного кластера (в другой тестовой среде), но исключения не возникает.

Другая информация, это исключение всегда после исключения сокета MongoDB, как показано ниже:

 Got socket exception on connection [connectionId{localValue:9, serverValue:11760}] to mongo-1:27017. All connections to mongo-1:27017 will be closed.
  

Ответ №1:

У нас была аналогичная проблема в нашем проекте: некоторые тесты завершались неудачно с 251 «Заданный номер транзакции * не соответствует ни одной текущей транзакции». Мы написали тест для воспроизведения проблемы, а затем отладили его. Я на 90% уверен, что мы нашли проблему.

Итак, гипотеза заключается в следующем:
когда мы используем транзакции spring mongo, фактическая транзакция запускается при отправке первого запроса в базу данных (неважно, какой запрос — запрос, обновление и т. Д.). Итак, Когда первый запрос отправляется параллельно с любыми другими запросами, но не былудалось завершить до них, и они думают, что транзакция запущена (но это не так), тогда мы видим, что возникает эта ошибка. «Транзакция x 1 не существует. Последняя транзакция — x». К такому выводу привела следующая последовательность журналов (мы включили журналы трассировки во время выполнения теста):

  • 2021-07-15 12:56:41.331 ОТЛАДКА 4900 — [Test worker] org.mongodb.driver.protocol.command : Отправка команды ‘{«find»: «items», «filter»: {«_id»: «d1»}, «limit»: 1, «$db»: «…», …, «txnNumber»: 1, «StartTransaction»: true, «autocommit»: false, …}’ с идентификатором запроса 23 к базе данных … при подключении …
  • 2021-07-15 12:56:41.334 ОТЛАДКА 4900 — [Test worker] org.mongodb.driver.protocol.command : Отправка команды ‘{«найти»: «элементы», «фильтр»: {«_id»: «d2»}, «limit»: 1, «$db»: «…», …, «txnNumber»: 1, «autocommit»: false, …}’ с идентификатором запроса 24 к базе данных … при подключении …
  • 2021-07-15 12:56:41.337 DEBUG 4900 — [ntLoopGroup-3-6] org.mongodb.driver.protocol.command : выполнение команды с идентификатором запроса 24 не удалось успешно завершить …
    com.mongodb.MongoCommandException: сбой команды с ошибкой 251 (NoSuchTransaction): «Задан номер транзакции 1не соответствует никаким текущим транзакциям. Номер активной транзакции равен -1′ на сервере …
  • 2021-07-15 12:56:41.379 ОТЛАДКА 4900 — [ntLoopGroup-3-8] org.mongodb.driver.protocol.command : выполнение команды с идентификатором запроса 23 успешно завершено …

Обратите внимание, что в первом журнале у нас есть «StartTransaction»: true, а во втором — нет. Тем не менее, второй запрос завершился первым, поэтому произошла ошибка. Эта ошибка также возникает, если второй запрос запускается между запуском первого запроса и выполнением первого запроса, например: первый запрос запускается, второй запрос запускается, первый запрос завершается, второй запрос завершается.

Тестовый код (на kotlin):

Обслуживание:

 @Service
class TestService {

    @Autowired private lateinit var itemRepository: ItemRepository

    @Transactional
    fun parallelQuery(): Mono<Void> {
        return Flux.fromIterable(listOf("d1", "d2"))
            .flatMap {
                itemRepository.findById(it)
            }
            .then()
    }
}
  

Сам тест:

 internal class MonoZipTest: BaseTest() {
    @Autowired private lateinit var testService: TestService

    @Test
    fun test() {

        val mono =
            Flux.fromIterable(1..1000)
                .flatMap {
                    testService.parallelQuery()
                }
                .then()

        StepVerifier.create(mono)
            .expectError(MongoTransactionException::class.java)
            .verify()
    }
}
  

Вывод: убедитесь, что первый запрос к mongodb в транзакции не выполняется параллельно с любым другим запросом в этой транзакции.

Комментарии:

1. Вау. Это был ответ. У меня была такая же проблема в mongoose. Выполнение первого запроса не параллельно, а остальных параллельно решило проблему. github.com/Automattic/mongoose/issues/11115

Ответ №2:

Небольшая оговорка: это неправильный ответ, поскольку я не уверен, что это может помочь оригинальному постеру; кроме того, у меня нет правильного объяснения этого эффекта. Я просто хотел, чтобы люди знали об этом эффекте; обычно я бы использовал для этого комментарий, но он слишком длинный для комментария. Я публикую это в надежде, что это может помочь кому-то решить их проблему.

Недавно мы видели подобное исключение:

 Caused by: com.mongodb.MongoQueryException: Query failed with error code 251 and error message 'Given transaction number 198 does not match any in-progress transactions. The active transaction number is 197' on server aaa.bbb.ccc:27017
    at com.mongodb.operation.FindOperation$3.onResult(FindOperation.java:822)
  

Я не могу показать код, поэтому я попытаюсь объяснить, что он делает.

В нереактивной настройке это было бы так:

 X = getX()
Y = saveAndReturnY()
pair = (X, Y)
processPair(pair)
  

Эта логика была реализована, и она работала нормально (я не показываю рабочую версию кода, это не имеет значения). Этот код выполнялся при транзакции.

Затем я переработал этот код, чтобы упростить его. В итоге это выглядело так:

 getX() // Mono<X>
    .zipWith(saveAndReturnY()) // Mono<Tuple<X, Y>>
    .flatMap(this::processPair)
  

И с этим кодом мы наблюдали исключение выше. Это происходило не в 100% случаев, что-то вроде 50/50: иногда это происходило, иногда нет. Это происходило только в MongoDB Atlas. Наши интеграционные тесты с использованием MongoDB той же версии (4.2.9), работающие в контейнере Docker (через testcontainers), работали нормально, и нам так и не удалось воспроизвести проблему там.

Короче говоря: оказалось, что если мы заменим zipWith() на zipWhen() , проблема исчезнет:

 getX() // Mono<X>
    .zipWhen(x -> saveAndReturnY()) // Mono<Tuple<X, Y>>
    .flatMap(this::processPair)
  

Разница в том, что с помощью подписки происходит одновременно с обоими монетами, объединенными вместе, то есть с и , поэтому они выполняются «параллельно». zipWith() Mono<X> Mono<Y> Но для zipWhen() , они выполняются строго последовательно: сначала вы X выходите Mono<X> , затем подписываетесь Mono<Y> . В исходном коде (до рефакторинга) он работал таким же (последовательным или, вероятно, лучше сказать, причинным) способом.

Я не уверен, почему это произошло для нас, мы все еще расследуем. Возможно, есть какая-то проблема, которая только что возникла из-за этого параллелизма. Или в транзакциях MongoDB есть что-то, чего я не понимаю (пока), что приводит к возникновению таких исключений при запуске параллелизма.

В любом случае, в нашем случае устранение параллелизма решило проблему. Попробуйте проанализировать свой код и посмотреть, есть ли какие-либо операторы, подобные Mono.zipWith() или Flux.flatMap() которые подписываются на более чем один Publisher , вызывая такой эффект «параллелизма».

Комментарии:

1. Спасибо за это объяснение, которое мне тоже помогло. Повышающий голос заслужен наверняка

Ответ №3:

Мой ответ может быть полезен для тех, кто использует mongoose для nodejs.

Я столкнулся с той же ошибкой. После исследования я выяснил, что проблема была вызвана конфликтами записи. Для проверки можно запустить db.currentOp() в mongosh.

Документы по этой команде: https://docs.mongodb.com/manual/faq/concurrency/#how-do-i-see-the-status-of-locks-on-my—instances —

Если есть некоторые конфликты записи, mongo повторяет операцию в транзакции до разрешения конфликтов, в моем случае это заняло более 60 секунд (максимальное время завершения транзакции по умолчанию), поэтому она была прервана.

Хорошая статья о конфликтах записи: https://blog.clairvoyantsoft.com/mongodb-transaction-management-884f82f62767