View Issue Details

IDProjectCategoryView StatusLast Update
0007025Talermechant backendpublic2022-11-04 20:52
Reportersebasjm Assigned Tosebasjm  
PriorityurgentSeveritycrashReproducibilityalways
Status closedResolutionfixed 
Product Versiongit (master) 
Target Version0.9Fixed in Version0.9 
Summary0007025: merchant database inconsistency after paying some orders
DescriptionThe merchant-backend reports: The service failed to fetch information from its database. (code 53)

The merchant logs reports:
ERROR Assertion failed at taler-merchant-httpd_private-get-orders.c:339.
ERROR Assertion failed at taler-merchant-httpd_private-get-orders.c:777.

It seems that it's when getting order from the database. Looking up the code, first the merchant does
TMH_db->lookup_orders
at 766 and which doing manually returns

        order_id | order_serial | creation_time | bool | bool | bool
------------------------+--------------+------------------+------+------+------
 2021.274-020C7M4QR5GYG | 6 | 1633096279000000 | f | f | f
 2021.274-00BCRHWC1BK26 | 5 | 1633095939000000 | f | f | f
 2021.274-02G87N48SX0PM | 4 | 1633095785000000 | f | f | f

for the first part (looking up the orders table) and

        order_id | order_serial | creation_time | bool | bool | bool
------------------------+--------------+------------------+------+------+------
 2021.274-020C7M4QR5GYG | 6 | 1633096279000000 | f | f | f
 2021.274-00BCRHWC1BK26 | 5 | 1633095939000000 | f | f | f
 2021.274-02G87N48SX0PM | 4 | 1633095785000000 | f | f | f
 2021.274-02T2DX94B69QM | 3 | 1633095091000000 | f | f | f
 2021.274-014FFPFHMBXYR | 2 | 1633094975000000 | f | f | f

for the second part (looking up the contract terms table)

So, order 2 and 3 are the candidates for trouble.

taler-merchant-httpd_private-get-orders.c:312 seems to assume that it is only needed to look for order in the contract terms table ONLY if was paid which seems to not take into consideration claimed-but-not-paid orders.

Either this is wrong or maybe we should not deleted the order in the first place.

I have no enough logs but seems that the prepare statement "delete_completed_order" at plugin_merchantdb_postgres.c:7908 delete _ALL_ the order that have contract_terms.

Saving this information here and I will push the proper test case if I manage to reproduce it.
TagsNo tags attached.

Activities

Christian Grothoff

2021-10-02 10:06

manager   ~0018424

8bb460c..813f0ea should fix this, alas untested as I don't have a "problematic" DB. Sebastian: Please check against the DB that you had where there was a problem, and add feedback and/or resolve the bug.

Christian Grothoff

2021-12-01 20:03

manager   ~0018566

Sebastian: this is EXACTLY the issue we hit with GLS today. So once your test works, please 'resolve' this one.

sebasjm

2021-12-02 05:11

developer   ~0018567

pushed b19d022e..ec1a49ed

Running in the fixed revision works ok

First, prepare wallet with coins... OK
Configuring merchant instance ...OK
Creating order to be claimed...Ok (order 2021.336-008BGX6H0SEBM)
Claim the order but do not pay it ... OK (took 2 secs )
wait 8 secs
Trying to get the list of orders...ok
Creating a new order that will trigger the db cleanup...Ok (order 2021.336-01E46GHTNRGJ2)
Trying to get the list of orders (issue 0007025)...ok
Now paying this order... OK (took 15 secs )
Trying to get the list of orders...ok
Finally, create another order...Ok (order 2021.336-02M6Q03VT8TW0)
Now paying this order... OK (took 20 secs )
Trying to get the list of orders...ok

running in the previous revision fails as expected

First, prepare wallet with coins... OK
Configuring merchant instance ...OK
Creating order to be claimed...Ok (order 2021.336-03G8PJ48XX2J8)
Claim the order but do not pay it ... OK (took 1 secs )
wait 8 secs
Trying to get the list of orders...ok
Creating a new order that will trigger the db cleanup...Ok (order 2021.336-030E0657BXR8R)
Trying to get the list of orders (issue 0007025)...should response ok. got: 500 { "code": 53, "hint": "The service failed to fetch information from its database." }

Issue History

Date Modified Username Field Change
2021-10-01 17:47 sebasjm New Issue
2021-10-01 17:47 sebasjm Status new => assigned
2021-10-01 17:47 sebasjm Assigned To => Christian Grothoff
2021-10-01 18:32 Christian Grothoff Priority normal => urgent
2021-10-01 18:32 Christian Grothoff Target Version git (master) => 0.8.5
2021-10-02 10:06 Christian Grothoff Note Added: 0018424
2021-10-02 10:06 Christian Grothoff Status assigned => feedback
2021-11-20 21:28 Christian Grothoff Assigned To Christian Grothoff => sebasjm
2021-12-01 20:03 Christian Grothoff Note Added: 0018566
2021-12-02 05:11 sebasjm Note Added: 0018567
2021-12-02 05:11 sebasjm Status feedback => resolved
2021-12-02 05:11 sebasjm Resolution open => fixed
2022-10-20 10:45 Christian Grothoff Target Version 0.8.5 => 0.9
2022-10-20 10:47 Christian Grothoff Fixed in Version => 0.9
2022-11-04 20:52 Christian Grothoff Status resolved => closed