View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0009780 | Taler | merchant backend | public | 2025-04-23 22:07 | 2025-04-26 10:36 |
| Reporter | Florian Dold | Assigned To | Christian Grothoff | ||
| Priority | normal | Severity | major | Reproducibility | have not tried |
| Status | feedback | Resolution | open | ||
| Product Version | git (master) | ||||
| Target Version | 1.0 | ||||
| Summary | 0009780: merchant fails to re-fetch GET /keys when exchange loses keys | ||||
| Description | On a /pay request, the merchant claims that the exchange is not responding: "hint": "Unexpected HTTP status (504) in response", "requestUrl": "http://localhost:8083/orders/2025.113-03PF97V0EQX4Y/pay", "requestMethod": "POST", "httpStatusCode": 504, "errorResponse": { "code": 2011, "hint": "The exchange failed to respond to the merchant on time." } However, the merchant *actually* just refuses to re-fetch keys in time: --- denom-unoffered/merchant-httpd-testmerchant-1-stderr.log 2025-04-23T21:05:08.797910+0200 taler-merchant-httpd-310062(2M7R2V83D8VECKBBY62NVH9DXW) INFO Have missing denomination for exchange, updating http://localhost:8081/ 2025-04-23T21:05:08.797914+0200 taler-merchant-httpd-310062(2M7R2V83D8VECKBBY62NVH9DXW) INFO Forcing /keys download (once) as wire fees are unknown --- denom-unoffered/merchant-exchangekeyupdate-testmerchant-1-stderr.log 2025-04-23T21:05:08.798036+0200 taler-merchant-exchangekeyupdate-310063 INFO Received notification xr6bnxxwqkrdeav03was555tqge98215a7ckh4a0jjdy7b8w6023g with extra data `http://localhost:8081/' 2025-04-23T21:05:08.798043+0200 taler-merchant-exchangekeyupdate-310063 INFO Received keys change notification: reload `http://localhost:8081/' 2025-04-23T21:05:08.798048+0200 taler-merchant-exchangekeyupdate-310063 INFO Will download http://localhost:8081/keys in 299 | ||||
| Steps To Reproduce | $ taler-harness run-integrationtests denom-unoffered | ||||
| Tags | No tags attached. | ||||
|
|
Sure, that's a little white lie. To avoid merchants DDoSing us by accident, we do enforce a minimum delay between /keys fetches, so IMO that's by design. You'll have to time-travel for 5 minutes. |
|
|
We can discuss if you want, but I don't consider this a bug, but "work as intended". |
|
|
I've added the time travel (6 minutes), and it still doesn't work: The merchant continues reporting 504. That is *despite* the merchant-exchangekeyupdate-testmerchant logs reporting a re-fetch of the exchange keys (*after* taler-exchange-httpd was restarted the keys purge, based on the log timestamps). |
|
|
Eh, which process did you timetravel? It looks like you send taler-merchant-httpd into the future, and not taler-merchant-exchangekeyupdate! |
|
|
I'm time-travelling them *both*! And indeed the taler-merchant-exchangekeyupdate is re-started with time-travel. See the harness logs: 2025-04-25T23:05:53.666Z harness.ts INFO spawning process (merchant-exchangekeyupdate-testmerchant-1): taler-merchant-exchangekeyupdate taler-merchant-exchangekeyupdate -LDEBUG -c '/tmp/taler-integrationtests-jpA5Vg/denom-unoffered/merchant-testmerchant-1.conf' '--timetravel=+360000000' Maybe the process doesn't properly support time travel?! |
|
|
Can't be, the timetravel logic is the same everywhere. But the timestamps I saw in the logs were completely different, with taler-merchant-exchangekeyupdate timestamps being 5 minutes *before* taler-merchant-httpd, and taler-merchant-httpd being 5 minutes after the file system time for the log file, so it definitively didn't look like exchangkeyupdate had time-travelled. |
| Date Modified | Username | Field | Change |
|---|---|---|---|
| 2025-04-23 22:07 | Florian Dold | New Issue | |
| 2025-04-23 22:07 | Florian Dold | Status | new => assigned |
| 2025-04-23 22:07 | Florian Dold | Assigned To | => Christian Grothoff |
| 2025-04-24 00:19 | Christian Grothoff | Note Added: 0024656 | |
| 2025-04-24 00:19 | Christian Grothoff | Assigned To | Christian Grothoff => |
| 2025-04-24 00:19 | Christian Grothoff | Status | assigned => acknowledged |
| 2025-04-24 00:19 | Christian Grothoff | Assigned To | => Florian Dold |
| 2025-04-24 00:19 | Christian Grothoff | Status | acknowledged => feedback |
| 2025-04-24 00:19 | Christian Grothoff | Note Added: 0024657 | |
| 2025-04-24 00:19 | Christian Grothoff | Product Version | => git (master) |
| 2025-04-25 16:14 | Florian Dold | Note Added: 0024671 | |
| 2025-04-25 16:14 | Florian Dold | Assigned To | Florian Dold => Christian Grothoff |
| 2025-04-25 22:17 | Christian Grothoff | Note Added: 0024673 | |
| 2025-04-25 22:17 | Christian Grothoff | Assigned To | Christian Grothoff => Florian Dold |
| 2025-04-26 01:07 | Florian Dold | Note Added: 0024674 | |
| 2025-04-26 01:07 | Florian Dold | Assigned To | Florian Dold => Christian Grothoff |
| 2025-04-26 10:36 | Christian Grothoff | Note Added: 0024682 |
