View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0011305 | Taler | merchant backend | public | 2026-03-25 18:30 | 2026-03-30 18:07 |
| Reporter | Florian Dold | Assigned To | Florian Dold | ||
| Priority | normal | Severity | minor | Reproducibility | have not tried |
| Status | assigned | Resolution | open | ||
| Target Version | 1.6 | ||||
| Summary | 0011305: merchant reports 502 on first payment attempt | ||||
| Description | The second attempt/retry seems to succeed. | ||||
| Additional Information | Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Handling request (POST) for URL '/instances/thaler/orders/2026.084-0167GZPR4MY3Y/pay' Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay in phase 0 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay in phase 1 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay in phase 2 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Handling payment for order `2026.084-0167GZPR4MY3Y' with contract hash `18PBW19K' Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay in phase 3 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay in phase 5 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Order brutto is CHF:1 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay in phase 6 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Starting merchant DB transaction `run pay' Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Rolling back merchant DB transaction `run pay' Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay in phase 11 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Getting /keys for https://exchange.stage.taler-ops.ch/ Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Trying to find chosen exchange `https://exchange.stage.taler-ops.ch/' Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO The exchange `https://exchange.stage.taler-ops.ch/' is ready Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay suspended in phase 11 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Returning key data for https://exchange.stage.taler-ops.ch/ instantly Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing find operations for `https://exchange.stage.taler-ops.ch/' Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing payment with keys from exchange https://exchange.stage.taler-ops.ch/ Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Account `payto://iban/CH5989144115421495546' allowed by regex Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO get_kyc_limits for payto://iban/CH5989144115421495546?receiver-name=Theodorius%20Thaler at https://exchange.stage.taler-ops.ch/ returned KYC OK/custom limits Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO KYC rule 0 with limit CHF:1000 applies Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Got wire data for https://exchange.stage.taler-ops.ch/ Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Initiating batch deposit with 1 coins Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Uploading JSON of 1233 bytes (compressed) Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Batch deposit completed with status 0 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) WARNING Deposit operation failed with HTTP code 0/10 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO HTTP request for `https://exchange.stage.taler-ops.ch/batch-deposit' finished with 0 after 147 ms Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay in phase 12 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Processing /pay in phase 14 Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Request for `/instances/thaler/orders/2026.084-0167GZPR4MY3Y/pay' completed with HTTP status 502 (0) | ||||
| Tags | No tags attached. | ||||
| Attached Files | |||||
|
|
Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Uploading JSON of 1233 bytes (compressed) Mar 25 18:04:28 betel taler-merchant-httpd[1034639]: (8QYG5V1E11M2FZWVH8MWDTK010) INFO Batch deposit completed with status 0 -- interesting, I wonder why it finished within < 1s without an HTTP response. Needs more logging... |
|
|
c68e54e97..73916d95c modifies exchange.git to add some logging to help figure this out. |
|
|
This is an http2 issue, logs mention a failed handshake when reusing a connection: Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: (5AMBGMREZABCAM8NFJA972XRQ4) INFO Uploading JSON of 5622 bytes (compressed) Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: * Hostname exchange.stage.taler-ops.ch was found in DNS cache Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: * Trying [2001:1680:101:940::1]:443... Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: * GnuTLS priority: NORMAL:-ARCFOUR-128:-CTYPE-ALL:+CTYPE-X509:-VERS-SSL3.0 Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: * SSL reusing session with ALPN 'h2' Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: * ALPN: curl offers h2,http/1.1 Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: * found 150 certificates in /etc/ssl/certs/ca-certificates.crt Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: * found 452 certificates in /etc/ssl/certs Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: * GnuTLS, handshake failed: The request is invalid. Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: * closing connection #2 Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: (5AMBGMREZABCAM8NFJA972XRQ4) INFO Batch deposit completed with status 0 Mar 27 20:09:36 betel taler-merchant-httpd[1096194]: (5AMBGMREZABCAM8NFJA972XRQ4) WARNING Deposit operation failed with HTTP code 0/10 |
| Date Modified | Username | Field | Change |
|---|---|---|---|
| 2026-03-25 18:30 | Florian Dold | New Issue | |
| 2026-03-25 18:30 | Florian Dold | File Added: rn_image_picker_lib_temp_356fcf2c-19ab-4882-88ca-4949782e28d3.jpg | |
| 2026-03-25 19:31 | Florian Dold | Target Version | => 1.5 |
| 2026-03-25 19:33 | Florian Dold | Additional Information Updated | |
| 2026-03-25 19:41 | Christian Grothoff | Note Added: 0028280 | |
| 2026-03-25 19:44 | Christian Grothoff | Note Added: 0028281 | |
| 2026-03-25 19:45 | Christian Grothoff | Assigned To | => Florian Dold |
| 2026-03-25 19:45 | Christian Grothoff | Status | new => assigned |
| 2026-03-26 16:02 | vecirex | Relationship added | related to 0011212 |
| 2026-03-30 18:04 | Florian Dold | Target Version | 1.5 => 1.6 |
| 2026-03-30 18:06 | Florian Dold | Note Added: 0028307 | |
| 2026-03-30 18:07 | Florian Dold | Relationship added | related to 0011223 |
