View Issue Details

IDProjectCategoryView StatusLast Update
0005647Talermerchant backendpublic2019-12-20 18:12
ReporterMarcello Stanisci Assigned ToChristian Grothoff Resolution deadline
ImplementerReviewer 
Release signed byDeployed by 
VerifierCommunicator 
Data protection authority notification requiredNo  
CSIRT notification requiredNo  
Estimated effort (hours)Actual effort (hours)0 
Fast-trackNo
Work packagenone
PrioritynormalSeverityblockReproducibilityhave not tried
Status closedResolutionfixed 
Product Versiongit (master) 
Target Version0.6Fixed in Version0.6 
Summary0005647: Database unusable, PROBABLY after failing transaction.
DescriptionThe backend fails upon calling the database query "find_order". According to the logs, this failing query occurs after a failed and non-rolledback transaction.

The failure relates to this version of the code (that is currently pointed to the 'stable' branch): 7820b4b0021ba63027d140765c4167feeee40246.
Additional InformationThe bug report was made by some user that tried to buy a article - didn't say which one - from the 'demo' blog.

Relevant logs for this problem got isolated under the directory: /home/demo-blue/democassee_report_logs/.

As usual, all the other logs are also found under: /home/demo-blue/logs/
TagsNo tags attached.
Attached Files

Required notifications

Address or linkRemarkAdded byNotifiedActions

Activities

Christian Grothoff

2019-04-06 14:29

manager   ~0014264

I've now manually gone over the entire backend transaction logic, added preflight() checks where applicable and fixed missing rollbacks (IIRC only one) where I could find them. I also introduced a naming convention to make it clearer which DB API functions run their own transaction or require an external transaction (or are one-shot and thus do neither). So this should now really be fixed, or if not, we should get MUCH better logs.

Marcello Stanisci

2019-04-15 18:18

reporter   ~0014291

I got some DB failures from the LCOV worker on Gv, and here I attach the logs (although they might not be _strictly_ related to this issue).
test-suite.log (273,187 bytes)

Christian Grothoff

2019-04-17 09:06

manager   ~0014298

Key lines from the log are:

Apr 15 19:58:58-362047 pq-18352 INFO Query `get_deposit' failed with result: could not serialize access due to read/write dependencies among transactions/Reason code: Canceled on conflict out to pivot 73962, during read./ERROR: could not serialize access due to read/write dependencies among transactions
DETAIL: Reason code: Canceled on conflict out to pivot 73962, during read.
HINT: The transaction might succeed if retried.

So basically, there is a DB transaction that we need to retry internally before throwing an error at the user.

Christian Grothoff

2019-04-18 12:41

manager   ~0014300

The retry logic is there, but the DB fails 100 times in a row on a simple GET request. My ONLY guess at this time is that some other operation left an uncommitted transaction on the 'orders' table hanging, which now conflicts.

I've added some additional instrumentation in 5d3ae965..32a3a0ff to help detect this, basically making sure that after MHD is done with any HTTP request, there are no pending transactions with that thread.

Christian Grothoff

2019-04-18 12:41

manager   ~0014301

Please monitor the logs and let me know if this happens again!

Christian Grothoff

2019-06-06 19:14

manager   ~0014515

I think the recent addition of the LOCK on the deposits table should fix this (by elimianting the retries problem).

Issue History

Date ModifiedUsernameFieldChange
2019-03-14 13:54Marcello StanisciNew Issue
2019-03-14 13:54Marcello StanisciStatusnew => assigned
2019-03-14 13:54Marcello StanisciAssigned To => Marcello Stanisci
2019-03-14 13:55Marcello StanisciAssigned ToMarcello Stanisci => Christian Grothoff
2019-04-06 07:32Christian GrothoffSeverityminor => block
2019-04-06 07:32Christian GrothoffProduct Version => git (master)
2019-04-06 07:32Christian GrothoffTarget Version => 0.6
2019-04-06 14:29Christian GrothoffStatusassigned => informing
2019-04-06 14:29Christian GrothoffResolutionopen => fixed
2019-04-06 14:29Christian GrothoffFixed in Version => 0.6
2019-04-06 14:29Christian GrothoffNote Added: 0014264
2019-04-15 18:18Marcello StanisciFile Added: test-suite.log
2019-04-15 18:18Marcello StanisciNote Added: 0014291
2019-04-17 09:06Christian GrothoffNote Added: 0014298
2019-04-17 09:06Christian GrothoffStatusinforming => assigned
2019-04-17 09:07Christian GrothoffStatusassigned => feedback
2019-04-17 09:07Christian GrothoffFixed in Version0.6 =>
2019-04-17 09:07Christian GrothoffStatusfeedback => assigned
2019-04-18 12:41Christian GrothoffNote Added: 0014300
2019-04-18 12:41Christian GrothoffAssigned ToChristian Grothoff => Marcello Stanisci
2019-04-18 12:41Christian GrothoffStatusassigned => feedback
2019-04-18 12:41Christian GrothoffNote Added: 0014301
2019-06-05 16:41Christian GrothoffAssigned ToMarcello Stanisci => Christian Grothoff
2019-06-05 16:41Christian GrothoffStatusfeedback => assigned
2019-06-06 19:14Christian GrothoffNote Added: 0014515
2019-06-06 19:16Christian GrothoffStatusassigned => informing
2019-06-06 19:16Christian GrothoffFixed in Version => 0.6
2019-12-20 18:12Christian GrothoffStatusinforming => closed
2025-03-22 13:09Christian GrothoffCategorymechant backend => merchant backend