View Issue Details

IDProjectCategoryView StatusLast Update
0005647Talermechant backendpublic2019-06-06 21:16
ReporterMarcello StanisciAssigned ToChristian Grothoff 
PrioritynormalSeverityblockReproducibilityhave not tried
Status resolvedResolutionfixed 
Product VersionSVN HEAD 
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.

Activities

Christian Grothoff

2019-04-06 16: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 20:18

manager   ~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 11: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 14: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 14:41

manager   ~0014301

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

Christian Grothoff

2019-06-06 21: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 Modified Username Field Change
2019-03-14 14:54 Marcello Stanisci New Issue
2019-03-14 14:54 Marcello Stanisci Status new => assigned
2019-03-14 14:54 Marcello Stanisci Assigned To => Marcello Stanisci
2019-03-14 14:55 Marcello Stanisci Assigned To Marcello Stanisci => Christian Grothoff
2019-04-06 09:32 Christian Grothoff Severity minor => block
2019-04-06 09:32 Christian Grothoff Product Version => SVN HEAD
2019-04-06 09:32 Christian Grothoff Target Version => 0.6
2019-04-06 16:29 Christian Grothoff Status assigned => resolved
2019-04-06 16:29 Christian Grothoff Resolution open => fixed
2019-04-06 16:29 Christian Grothoff Fixed in Version => 0.6
2019-04-06 16:29 Christian Grothoff Note Added: 0014264
2019-04-15 20:18 Marcello Stanisci File Added: test-suite.log
2019-04-15 20:18 Marcello Stanisci Note Added: 0014291
2019-04-17 11:06 Christian Grothoff Note Added: 0014298
2019-04-17 11:06 Christian Grothoff Status resolved => assigned
2019-04-17 11:07 Christian Grothoff Status assigned => feedback
2019-04-17 11:07 Christian Grothoff Fixed in Version 0.6 =>
2019-04-17 11:07 Christian Grothoff Status feedback => assigned
2019-04-18 14:41 Christian Grothoff Note Added: 0014300
2019-04-18 14:41 Christian Grothoff Assigned To Christian Grothoff => Marcello Stanisci
2019-04-18 14:41 Christian Grothoff Status assigned => feedback
2019-04-18 14:41 Christian Grothoff Note Added: 0014301
2019-06-05 18:41 Christian Grothoff Assigned To Marcello Stanisci => Christian Grothoff
2019-06-05 18:41 Christian Grothoff Status feedback => assigned
2019-06-06 21:14 Christian Grothoff Note Added: 0014515
2019-06-06 21:16 Christian Grothoff Status assigned => resolved
2019-06-06 21:16 Christian Grothoff Fixed in Version => 0.6