View Issue Details
|ID||Project||Category||View Status||Date Submitted||Last Update|
|0005647||Taler||mechant backend||public||2019-03-14 14:54||2019-06-06 21:16|
|Reporter||Marcello Stanisci||Assigned To||Christian Grothoff|
|Priority||normal||Severity||block||Reproducibility||have not tried|
|Product Version||SVN HEAD|
|Target Version||0.6||Fixed in Version||0.6|
|Summary||0005647: Database unusable, PROBABLY after failing transaction.|
|Description||The 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 Information||The 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/
|Tags||No tags attached.|
||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.|
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)
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.
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.
||Please monitor the logs and let me know if this happens again!|
||I think the recent addition of the LOCK on the deposits table should fix this (by elimianting the retries problem).|
|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|