fix: resolve lock-wait timeouts and cut repost overhead in loan write off and repayment repost (backport #1315)#1318
Merged
Conversation
…repost Bulk Loan Write Off submitted all documents in one request transaction, so locks on the shared suspense and waiver accounts were held across the whole batch and hit Lock wait timeout exceeded (1205). Enable queue_in_background on Loan Write Off so each document submits in its own background job and transaction, releasing locks between documents. Loan Repayment created its repost and submitted it inline inside the repayment background job, holding locks for the full repost and timing out on the Loan Repayment Repost Detail insert. Enqueue the repost as its own per-loan deduplicated background job instead. Also cache Loan Product and Company master reads with get_cached_value in the repayment, write off and loan paths to cut repeated per-transaction lookups. Mutable reads such as Loan status are left as live reads. (cherry picked from commit 34912b1) # Conflicts: # lending/loan_management/doctype/loan/loan.py
Skip the per-document realtime publish (doc_update/list_update) during a bulk repost, where no UI is watching, by setting flags.notify_update = False on the accrual and demand documents created and cancelled under frappe.flags.on_repost. Batch-fetch data that was previously queried once per iteration: principal outstanding for penal interest, Loan Demand details for charge waiver credit notes, and Sales Invoice debit accounts for charge GL entries. The penal interest batch fetch keeps get_value's creation-desc selection to stay behaviour-compatible when duplicate cancelled and submitted demands exist. Cache get_per_day_interest by calendar year inside the penal interest loop, since its only date-dependent input is the year divisor. (cherry picked from commit 0b1d38f)
The per-loan dedup job id dropped the enqueue for a second repost when two repayments for the same loan were submitted back to back, leaving that repost stuck in draft. Key the job id on the repost name instead, so every repost is enqueued and processed. deduplicate is kept to guard against the same repost being enqueued twice. Mark the repost Queued while it waits, matching the existing long repost path. (cherry picked from commit b81a93e)
Author
|
Cherry-pick of 34912b1 has failed: To fix up this pull request, you can check it out locally. See documentation: https://docs.github.com/en/pull-requests/collaborating-with-pull-requests/reviewing-changes-in-pull-requests/checking-out-pull-requests-locally |
Author
|
Tick the box to add this pull request to the merge queue (same as
|
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Production hit intermittent
Lock wait timeout exceeded (1205),Deadlock found (1213), andTimestampMismatchErrorduring bulk Loan Write Off submission and Loan Repayment Repost, plus reposts that ran for hours.This PR fixes the root causes:
Root Cause Analysis
Issue 1 — Bulk Loan Write Off:
Lock wait timeout exceeded (1205)What happened (before)
Frappe's bulk action submitted all documents in one request = one transaction and only committed at the end.
Every Loan Write Off posts a Journal Entry into the same shared suspense/waiver accounts. So the whole batch serialised on those account rows, holding locks for the entire batch.
When a concurrent process needed the same rows for longer than
innodb_lock_wait_timeout(120s in client prod), it failed with1205. In the client log the batch broke at document 13 of 30.The same contention also surfaced as
Deadlock (1213)andTimestampMismatchError, the classic trio of concurrent-write contention on shared rows.Why we changed it
The documents do not need to share a transaction. Each Loan Write Off should submit and commit independently so its account locks release immediately.
The change
Set
queue_in_background: 1on the Loan Write Off DocType.Frappe's bulk action then routes each document through
queue_submission, giving each document its own background job = its own transaction.Single (non-bulk) submits are unaffected.
+ "queue_in_background": 1,Before / After (measured on dev, 50 real loans, rolled back)
Extra benefit
One failing write off no longer aborts the batch. Each is an isolated, independently retryable job.
Failures surface in the Submission Queue instead of instantly in the UI.
Issue 2 — Loan Repayment Repost:
1205on Repost Detail insertWhat happened (before)
LoanRepayment.create_repost created a Loan Repayment Repost and called repost.submit() inline, inside the repayment's own background job.
A repost regenerates hundreds of accruals, demands, GL and Journal Entries and takes for_update row locks.
Running it in the repayment's transaction kept those locks held for the full repost, so concurrent repayments on the same loan/applicant collided and timed out on the Loan Repayment Repost Detail insert.
Why we changed it
The repost should not extend the repayment's transaction — it should run as its own background job so the repayment commits and releases its locks immediately.
The change
create_repost now inserts the repost and enqueues it as its own background job (enqueue_after_commit=True) instead of submitting inline. Each repost is enqueued under a unique job_id (loan_repayment_repost::{repost.name}), so every repost is enqueued and processed and none is left orphaned in draft.
Note: this does not serialise concurrent reposts for the same loan; each repost runs as an independent job. In the normal flow, backdated repayments are processed sequentially. If strict per-loan serialisation is required, it can be added in a follow-up (per-loan job_id + a pick-any-pending drain of Queued reposts).
Before / After
Before
1205lock wait timeouts.After
Issue 3 — Repost duration: per-document overhead
A production profile of one repost the loan showed 12,915 s (~3.6 h) for ~200,000 document operations (If Repost from two years ago).
Three removable overheads dominated.
3a. Realtime UI events (~31% of the profile, 207,684 calls)
Every document save/cancel fired
notify_update -> publish_realtime(websocket/redis) to update a UI that nobody watches during a background repost.Change
Set
flags.notify_update = Falseon the accrual/demand documents created and cancelled underfrappe.flags.on_repost.This is honoured by core:
No financial data changes.
3b. One DB query per iteration
calculate_penal_interest_for_loans,make_credit_note_for_charge_waiversand the charge GL path each ran oneget_valueper demand/row.Change
Batch-fetch once with
get_all(... "name"/detail in [...]).The penal-interest principal lookup is filtered by:
This combination is not unique. Cancelled and submitted duplicates coexist (common right after a repost).
The original
get_valuereturned the row ordered by:(
Loan Demanddefaultsort_orderiscreation desc.)The batch version mirrors this exactly:
order_by="creation desc"Verified against
get_valueacross 144 duplicate details on 26 loans (including an 11-way duplicate) with 0 mismatches.The other two maps key by
name(primary key, unique), so no selection ambiguity.3c. Repeated interest recomputation
get_per_day_interestwas recomputed for every day in the penal date range, though its only date-dependent input is the year divisor.Change
Cache
get_per_day_interestby calendar year within the loop.Before / After (measured on dev, real data, rolled back)
Also included: master-read caching (Issue 1/2 support)
Repeated
frappe.db.get_value("Loan Product"/"Company", ...)for the same master record within a transaction were converted tofrappe.get_cached_valuein the repayment, write off and loan paths.Masters are immutable within a transaction, so the row is fetched once and reused.
Mutable reads (e.g.
Loan.status, which the code writes mid-transaction) were left as liveget_valueto avoid stale reads.This is an automatic backport of pull request #1315 done by Mergify.