View Issue Details

IDProjectCategoryView StatusLast Update
0009382Talerexchangepublic2024-12-13 19:15
ReporterFlorian Dold Assigned ToChristian Grothoff  
PrioritynormalSeverityminorReproducibilityhave not tried
Status closedResolutionfixed 
Target Version0.14Fixed in Version0.14 
Summary0009382: failed AMP results in DB error
Description$ taler-harness run-integrationtests kyc-amp-failure
Additional Information2024-12-11T18:35:25.963949+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Remembering rule R1 as triggered
2024-12-11T18:35:25.964385+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Got 0 additional transactions for this batch-withdrawal and limit 1733852125963927
2024-12-11T18:35:25.964390+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Triggered rule is R1
2024-12-11T18:35:25.964395+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO KYC requirement is R1
2024-12-11T18:35:25.965538+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Running AML program taler-harness aml-program run-program --name fail
{}2024-12-11T18:35:25.966138+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Passing 2 bytes to JSON conversion tool
2024-12-11T18:35:25.966160+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Trying to start child management.
2024-12-11T18:35:25.966171+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Child management started.
2024-12-11T18:35:25.966183+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Committing transaction `legi-check-run-start-precheck'
2024-12-11T18:35:25.969493+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO batch-withdraw processing in phase 3
2024-12-11T17:35:26.144Z taler-harness:index.ts INFO got input: {}
2024-12-11T17:35:26.145Z taler-harness:index.ts ERROR unhandledRejection [
  "I am a failed KYC program, oh my!"
]
2024-12-11T17:35:26.215Z taler-harness:index.ts ERROR stack [
  "Error: I am a failed KYC program, oh my!\n at Object.logic (/home/fdold-work/local/lib/taler-harness/node_modules/taler-harness/src/index.ts:1457:13)\n at CommandGroup.myAction (/home/fdold-work/local/lib/taler-harness/node_modules/taler-harness/src/index.ts:1524:27)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)"
]
2024-12-11T18:35:26.223503+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Conversion helper exited with status 3 and code 2 after outputting 3 bytes of data
2024-12-11T18:35:26.223540+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO AML program output is:
{}2024-12-11T18:35:26.223555+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Starting transaction `kyc-persist-aml-program-result'
2024-12-11T18:35:26.223702+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO AML program finished with status 1
2024-12-11T18:35:26.224067+0100 pq-4055133(R4GX6KY8E04SV4G1TX289CZXR0) ERROR PQprepare (`SELECT out_update FROM exchange_do_insert_aml_program_failure ($1, $2, $3, $4);' as `insert_aml_program_failure') failed with error: ERROR: function exchange_do_insert_aml_program_failure(unknown, unknown, unknown, unknown) does not exist
LINE 1: SELECT out_update FROM exchange_do_insert_aml_program_failur...
                               ^
HINT: No function matches the given name and argument types. You might need to add explicit type casts.

2024-12-11T18:35:26.224103+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) ERROR Assertion failed at pg_insert_aml_program_failure.c:60.
2024-12-11T18:35:26.224113+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) ERROR Assertion failed at exchangedb_aml.c:56.
2024-12-11T18:35:26.224118+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) ERROR Assertion failed at taler-exchange-httpd_common_kyc.c:193.
2024-12-11T18:35:26.224122+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Rolling back transaction
2024-12-11T18:35:26.224141+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) ERROR Assertion failed at taler-exchange-httpd_common_kyc.c:1046.
2024-12-11T18:35:26.224188+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Handling request (POST) for URL '/reserves/KK1GWP05A2CQK9SRG9NV47ENSM24CB3NJH12S1Y397CV3BWXWKJ0/batch-withdraw'
2024-12-11T18:35:26.224195+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO batch-withdraw processing in phase 8
2024-12-11T18:35:26.224287+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Request for `/reserves/KK1GWP05A2CQK9SRG9NV47ENSM24CB3NJH12S1Y397CV3BWXWKJ0/batch-withdraw' completed with HTTP status 500 (0)
2024-12-11T18:35:27.234014+0100 taler-exchange-httpd-4055133(R4GX6KY8E04SV4G1TX289CZXR0) INFO Handling new request
2024-12-11T18:35:27.234071+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Handling request (POST) for URL '/reserves/KK1GWP05A2CQK9SRG9NV47ENSM24CB3NJH12S1Y397CV3BWXWKJ0/batch-withdraw'
2024-12-11T18:35:27.234103+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Handling request (POST) for URL '/reserves/KK1GWP05A2CQK9SRG9NV47ENSM24CB3NJH12S1Y397CV3BWXWKJ0/batch-withdraw'
2024-12-11T18:35:27.234116+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Handling request (POST) for URL '/reserves/KK1GWP05A2CQK9SRG9NV47ENSM24CB3NJH12S1Y397CV3BWXWKJ0/batch-withdraw'
2024-12-11T18:35:27.234236+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO batch-withdraw processing in phase 0
2024-12-11T18:35:27.234736+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO batch-withdraw processing in phase 1
2024-12-11T18:35:27.234746+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO batch-withdraw processing in phase 2
2024-12-11T18:35:27.235116+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Starting transaction `legi-check-run-start-precheck'
2024-12-11T18:35:27.235340+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO get_kyc_rules returned 1/0/1/0
2024-12-11T18:35:27.235347+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO KYC: default KYC rules apply to this account!
2024-12-11T18:35:27.235353+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Testing 1 KYC rules for trigger 1
2024-12-11T18:35:27.235361+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Matched rule 0 with timeframe 1 day and threshold TESTKUDOS:10
2024-12-11T18:35:27.235369+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO KYC: Checking amounts until Tue Dec 10 18:35:27 2024
2024-12-11T18:35:27.235374+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Signaling amount TESTKUDOS:19.99 for KYC check during batch-withdrawal
2024-12-11T18:35:27.235382+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO KYC checking transaction amount TESTKUDOS:19.99 from Wed Dec 11 18:35:27 2024 against 1 rules
2024-12-11T18:35:27.235387+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Remembering rule R1 as triggered
2024-12-11T18:35:27.235584+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Got 0 additional transactions for this batch-withdrawal and limit 1733852127235366
2024-12-11T18:35:27.235591+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Triggered rule is R1
2024-12-11T18:35:27.235595+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO KYC requirement is R1
2024-12-11T18:35:27.235949+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Running AML program taler-harness aml-program run-program --name fail
{}2024-12-11T18:35:27.236506+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Passing 2 bytes to JSON conversion tool
2024-12-11T18:35:27.236527+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Trying to start child management.
2024-12-11T18:35:27.236543+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Committing transaction `legi-check-run-start-precheck'
2024-12-11T18:35:27.247408+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO batch-withdraw processing in phase 3
2024-12-11T17:35:27.426Z taler-harness:index.ts INFO got input: {}
2024-12-11T17:35:27.427Z taler-harness:index.ts ERROR unhandledRejection [
  "I am a failed KYC program, oh my!"
]
2024-12-11T17:35:27.496Z taler-harness:index.ts ERROR stack [
  "Error: I am a failed KYC program, oh my!\n at Object.logic (/home/fdold-work/local/lib/taler-harness/node_modules/taler-harness/src/index.ts:1457:13)\n at CommandGroup.myAction (/home/fdold-work/local/lib/taler-harness/node_modules/taler-harness/src/index.ts:1524:27)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)"
]
2024-12-11T18:35:27.506458+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Conversion helper exited with status 3 and code 2 after outputting 3 bytes of data
2024-12-11T18:35:27.506495+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO AML program output is:
{}2024-12-11T18:35:27.506511+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Starting transaction `kyc-persist-aml-program-result'
2024-12-11T18:35:27.506610+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO AML program finished with status 1
2024-12-11T18:35:27.506938+0100 pq-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) ERROR PQprepare (`SELECT out_update FROM exchange_do_insert_aml_program_failure ($1, $2, $3, $4);' as `insert_aml_program_failure') failed with error: ERROR: function exchange_do_insert_aml_program_failure(unknown, unknown, unknown, unknown) does not exist
LINE 1: SELECT out_update FROM exchange_do_insert_aml_program_failur...
                               ^
HINT: No function matches the given name and argument types. You might need to add explicit type casts.

2024-12-11T18:35:27.506984+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) ERROR Assertion failed at pg_insert_aml_program_failure.c:60.
2024-12-11T18:35:27.506993+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) ERROR Assertion failed at exchangedb_aml.c:56.
2024-12-11T18:35:27.506999+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) ERROR Assertion failed at taler-exchange-httpd_common_kyc.c:193.
2024-12-11T18:35:27.507007+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Rolling back transaction
2024-12-11T18:35:27.507031+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) ERROR Assertion failed at taler-exchange-httpd_common_kyc.c:1046.
2024-12-11T18:35:27.507083+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Handling request (POST) for URL '/reserves/KK1GWP05A2CQK9SRG9NV47ENSM24CB3NJH12S1Y397CV3BWXWKJ0/batch-withdraw'
2024-12-11T18:35:27.507093+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO batch-withdraw processing in phase 8
2024-12-11T18:35:27.507200+0100 taler-exchange-httpd-4055133(HT2R90VB3EA9AXA383PK9E1ZZ8) INFO Request for `/reserves/KK1GWP05A2CQK9SRG9NV47ENSM24CB3NJH12S1Y397CV3BWXWKJ0/batch-withdraw' completed with HTTP status 500 (0)
TagsNo tags attached.

Activities

Florian Dold

2024-12-11 18:38

manager   ~0023862

(Note that the test is not expected to terminate yet.)

Florian Dold

2024-12-11 18:52

manager   ~0023863

Test fixed. Not complete, but should terminate.

Christian Grothoff

2024-12-11 21:43

manager   ~0023866

19c0c0041..550a9adee fixes the exchange database issue. Test doesn't pass, but I think the specific bug is fixed.

Issue History

Date Modified Username Field Change
2024-12-11 18:37 Florian Dold New Issue
2024-12-11 18:37 Florian Dold Status new => assigned
2024-12-11 18:37 Florian Dold Assigned To => Christian Grothoff
2024-12-11 18:38 Florian Dold Note Added: 0023862
2024-12-11 18:52 Florian Dold Note Added: 0023863
2024-12-11 21:43 Christian Grothoff Note Added: 0023866
2024-12-11 21:43 Christian Grothoff Status assigned => resolved
2024-12-11 21:43 Christian Grothoff Resolution open => fixed
2024-12-11 21:43 Christian Grothoff Fixed in Version => 0.14
2024-12-13 19:15 Christian Grothoff Status resolved => closed