Hacktoberfest 2026: the issues maintainers tagged for October, open and beginner-friendly. Browse Hacktoberfest issues

Transaction recovery takes a transaction whose final status it reads one poll later for a failed one

Open
  • Is something wrong?
#4,986 0 comments 0 reactions 0 assignees View on GitHub

Maintainers usually reply within 1 day

Nobody has claimed this yet.

Assessment

Difficulty
4/5
Estimated time
3-5 days
Newbie friendliness
45/100
Issue type
Bug
Clarity
Mostly clear
Activity status
Active
Tech stack
java
Domain
backend, databases, distributed-systems

Research direction

Start with StandardTransactionLogProcessor and KCVSLog to understand how recovery tracks processed log progress and expires transactions. Run the named JanusGraphIndexTest replay and recovery tests, plus the JanusGraph user-log recovery test, with their recovery-graph read options. Done means late final statuses are not double-counted, repairs are counted after being attempted, and the replay tests pass without fixed sleeps.

Written by the indexing model from the issue text.

Description

Bug

Transaction recovery (StandardTransactionLogProcessor) gives up on a transaction tx.max-commit-time after it has read one of the transaction's log entries (5 s at least). But it reads the transaction log in polls:

  • one every log.tx.read-interval (5 s by default);
  • each covering the log up to log.tx.read-lag-time back;
  • none going past the end of the 100 s timeslice it is in.

So recovery can read a transaction's final status up to two read intervals after its first entry, even when the commit took far less than tx.max-commit-time. The read lag cancels out: it delays every entry equally.

When the final status arrives after the expiry, recovery takes a transaction that succeeded for a failed one:

  1. It treats the transaction as failed at PRIMARY_SUCCESS, restores the index documents of every element the transaction changed, and sends its user-log event again. A LogProcessorFramework processor then receives the transaction twice. The recovery docs (#4965) describe this as a risk only for commits that outlast tx.max-commit-time, but it also happens to commits that finished well inside it.
  2. The late final status creates a second, empty entry for the same transaction. That entry expires as another transaction ("Trying to repair expired or unpersisted transaction"), so the transaction is counted twice.

How likely this is depends on how close tx.max-commit-time is to the read interval. With both at 5 s, the least recovery waits, a final status read one poll after the first entry arrives within milliseconds of the expiry, either before or after it.

Reproduction

A new JanusGraphIndexTest.testRecoveryWaitsForAFinalStatusReadOnePollLater:

  • Settings: tx.max-commit-time 5 s, log.tx.read-interval 6 s, log.tx.read-lag-time 2 s.
  • The transaction writes a user log, and its index write takes 3 s and then succeeds.
  • Recovery is started as the commit returns. Its first poll takes in the commit's first entries but not the final status, which was written less than 2 s earlier. The next poll comes 6 s later, after the entry has expired.

On master it fails 3 times out of 3 with expected: <1> but was: <2> user-log events.

The flaky replay tests

This is also behind the flaky JanusGraphIndexTest replay tests (testIndexReplay, testRecurringIndexReplay, testRecurringIndexReplayWithDifferentStartTime). They are BRITTLE, so of the CI jobs only the Solr jobs run them. They have three problems:

  • Default read options on the recovery graph. They start recovery on a graph opened by a plain clopen(). That drops the log.tx.read-interval of 250 ms and log.tx.read-lag-time of 50 ms they set earlier, because both options are MASKABLE. Recovery therefore polls every 5 s against a 5 s expiry (tx.max-commit-time is 1 s, raised to the 5 s minimum). Locally the last transaction's final status is written less than 500 ms before the first poll, so only the next poll reads it, within milliseconds of the expiry.
    • Locally, BerkeleyLuceneTest.testIndexReplay failed with expected: <4> but was: <5>.
    • With verbose recovery, runs show that transaction being repaired twice, the second time as "expired or unpersisted".
  • A fixed 12 s wait. When a 100 s timeslice boundary falls between the schema transaction and the others, the others are read one poll later. They then expire just after the cleaner's second pass and are only counted at shutdown, after the test has read the statistics. This produced CQLSolrTest.testRecurringIndexReplay:2585 expected: <4> but was: <0> in run 36059281715, where the success count of 1 had already been reached.
  • Counting before the repair. getStatistics() counts a failed transaction before its repair starts. The repair runs on Caffeine's removal-listener executor, so a caller that sees the count cannot tell whether the repair has finished.
Fix
  • Recovery gives a transaction up by how far it has read the log rather than after a wall-clock wait: once the log has been read, and its messages processed, up to tx.max-commit-time past the transaction's start. A wall-clock allowance can't cover it: polls start a read interval after the previous one ended, reads are retried for up to log.tx.max-read-time, and all partitions share the read threads. KCVSLog now tracks how far its readers have processed what it read, and the recovery's cache uses that as its clock.
  • A failed transaction is counted once its repair has been attempted.
  • The replay tests pass the fast read options to the graph they start recovery on, and wait for the statistics instead of sleeping a fixed 12 s, then long enough for a double count to show. The user-log recovery test in JanusGraphTest gets the same options on its recovery graph.

A commit that really does outlast tx.max-commit-time, or whose instance fails between its user-log write and its final status, still gets its user-log event sent again. That is at-least-once delivery, and recovery cannot tell such a case from a failed user-log write. The repeat carries the transaction id of the original.

Dominant language
Java
Stars
5.8k
Forks
1.2k
Avg merge
20h 36m
Merged PRs (30d)
25

Getting set up

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

More from JanusGraph/janusgraph

All issues in JanusGraph/janusgraph

Similar issues

More Java issues

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.