View Issue Details

IDProjectCategoryView StatusLast Update
0007285Talerauditorpublic2022-11-04 20:53
Reporteroec Assigned ToChristian Grothoff  
PrioritynormalSeverityminorReproducibilityalways
Status closedResolutionfixed 
Product Versiongit (master) 
Target Version0.9Fixed in Version0.9 
Summary0007285: make check in auditor fails
DescriptionCalling `make check` in `src/auditor`. The call to make hangs.

```
⋯ nge/src/auditor • tail -f test-auditor.sh.log
Testing for jq
Testing for taler-bank-manage
Testing for pdflatex
Testing for taler-wallet-cli FOUND. Generating fresh database at /tmp/taler-auditor-basedbQBZS0k
/home/oec/projects/diss/code/exchange/src/auditor
Testing for taler-bank-manage FOUND
Testing for taler-wallet-cli FOUND
Testing for curl FOUND
/home/oec/projects/diss/code/exchange/src/auditor
Generating 1 keys, please wait.
Abgeschlossen!
Generating 1 keys, please wait.
Abgeschlossen!
AUDITOR PUB is CV9AMJ8WHAVT3ES37G3FGC9TVZRQ7ECMFJTCVV4T808P37G5E9B0 using file /home/oec/projects/diss/code/exchange/src/auditor/generate_auditordb_home//.local/share/taler//auditor/offline-keys/auditor.priv
Setting up exchange
Setting up merchant
Setting up auditor
Launching services
...................... DONE
Setting up keys.. DONE
Adding auditor signatures ... DONE
Setting up merchant % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
100 498 100 155 100 343 143k 316k --:--:-- --:--:-- --:--:-- 486k
{
  "hint": "The JSON in the client's request was malformed (generic parse error).",
  "code": 22,
  "field": "default_wire_transfer_delay",
  "line": 12
} DONE
Running wallet
```

```
⋯ nge/src/auditor • tail taler-exchange-wirewatch.log
2022-07-20T18:30:04.935255+0200 taler-exchange-wirewatch-4002123 WARNUNG External protocol violation detected at json_helper.c:638.
2022-07-20T18:30:04.935312+0200 taler-exchange-wirewatch-4002123 WARNUNG Parsing failed for field `date:1`
2022-07-20T18:30:04.935329+0200 taler-exchange-wirewatch-4002123 WARNUNG External protocol violation detected at bank_api_credit.c:120.
2022-07-20T18:30:04.935344+0200 taler-exchange-wirewatch-4002123 WARNUNG External protocol violation detected at bank_api_credit.c:169.
2022-07-20T18:30:04.935361+0200 taler-exchange-wirewatch-4002123 FEHLER Error fetching history: The response we got from the server was not even in JSON format. (0)
2022-07-20T18:30:06.092294+0200 taler-exchange-wirewatch-4002123 WARNUNG External protocol violation detected at json_helper.c:638.
2022-07-20T18:30:06.092334+0200 taler-exchange-wirewatch-4002123 WARNUNG Parsing failed for field `date:1`
2022-07-20T18:30:06.092345+0200 taler-exchange-wirewatch-4002123 WARNUNG External protocol violation detected at bank_api_credit.c:120.
2022-07-20T18:30:06.092354+0200 taler-exchange-wirewatch-4002123 WARNUNG External protocol violation detected at bank_api_credit.c:169.
2022-07-20T18:30:06.092365+0200 taler-exchange-wirewatch-4002123 FEHLER Error fetching history: The response we got from the server was not even in JSON format. (0)
```

```
⋯ nge/src/auditor • tail -f taler-exchange-httpd.log
2022-07-20T18:33:04.097785+0200 taler-exchange-httpd-4002962(5EH4YX8WKW9FBJGG680C8YFB3C) WARNUNG No denomination keys available. Refusing to generate /keys response.
2022-07-20T18:33:04.099745+0200 taler-exchange-httpd-4002962(6PKNRX7F7771TSBGMTRK4A9198) WARNUNG No denomination keys available. Refusing to generate /keys response
```


Additional InformationAll latest git checkouts: gnunet, exchange, merchant
TagsNo tags attached.

Activities

oec

2022-07-21 17:54

developer   ~0018964

I also see the following repeatedly in taler-exchange-wirewatch.log:

```
2022-07-21T17:53:57.401329+0200 taler-exchange-wirewatch-56184 FEHLER Error fetching history: The response we got from the server was not even in JSON format. (0)
2022-07-21T17:53:58.553536+0200 taler-exchange-wirewatch-56184 WARNUNG External protocol violation detected at json_helper.c:638.
2022-07-21T17:53:58.553589+0200 taler-exchange-wirewatch-56184 WARNUNG Parsing failed for field `date:1`
2022-07-21T17:53:58.553599+0200 taler-exchange-wirewatch-56184 WARNUNG External protocol violation detected at bank_api_credit.c:120.
2022-07-21T17:53:58.553608+0200 taler-exchange-wirewatch-56184 WARNUNG External protocol violation detected at bank_api_credit.c:169.
{
  "incoming_transactions": [
    {
      "row_id": 2,
      "amount": "TESTKUDOS:10.00",
      "date": {
        "t_ms": 1658418761000
      },
      "reserve_pub": "TGSPEBANZJX0TT39WTNWCN1DXH9AK0MJNJ9BZVD5FW18MKAAYDEG",
      "credit_account": "payto://x-taler-bank/localhost/Exchange",
      "debit_account": "payto://x-taler-bank/localhost/testuser-euwq6zzs"
    }
  ]
}2022-07-21T17:53:58.553769+0200 taler-exchange-wirewatch-56184 FEHLER Error fetching history: The response we got from the server was not even in JSON format. (0)
```

oec

2022-07-22 12:59

developer   ~0018969

This is related to the commit 78cba4124a993ba97923ff0543f2a5942f297cdc in gnunet (drop of "t_ms" in the encoding of a date).

The culprit seems to be that "talerbank" still encodes "t_ms", in ~/.local/python3.10/site-packages/talerbank/app/views.py

```
def build_history_response(qs, cancelled, user_account):
    history = []
    for entry in qs:
        counterpart = entry.credit_account.account_no
        sign_ = "-"
        if entry.cancelled and cancelled == "omit":
            continue
        if entry.credit_account.account_no == user_account.bankaccount.account_no:
            counterpart = entry.debit_account.account_no
            sign_ = "+"
        cancel = "cancel" if entry.cancelled else ""
        sign_ = cancel + sign_
        history.append(
            dict(
                counterpart=counterpart,
                amount=entry.amount.stringify(),
                sign=sign_,
                wt_subject=entry.subject,
                row_id=entry.id,
                date=dict(t_ms=int(entry.date.timestamp()) * 1000),
            )
        )
    return history

```

oec

2022-07-22 13:13

developer   ~0018970

After changing all "t_ms" in views.py to "t_s" (without *1000), I can confirm that the test continues to run.

However, `make check` still fails at
- test-autitor.sh
- test-revocation.sh
- test-sync.sh

See test-suite.log attached
test-suite.log (42,882 bytes)   
======================================================
   taler-exchange 0.8.5: src/auditor/test-suite.log
======================================================

# TOTAL: 3
# PASS:  0
# SKIP:  0
# XFAIL: 0
# FAIL:  3
# XPASS: 0
# ERROR: 0

.. contents:: :depth: 2

FAIL: test-auditor.sh
=====================

Testing for jq
Testing for taler-bank-manage
Testing for pdflatex
Testing for taler-wallet-cli FOUND. Generating fresh database at /tmp/taler-auditor-basedbCWOgB9
/home/oec/projects/diss/code/exchange/src/auditor
Testing for taler-bank-manage FOUND
Testing for taler-wallet-cli FOUND
Testing for curl FOUND
/home/oec/projects/diss/code/exchange/src/auditor
Generating 1 keys, please wait.
Abgeschlossen!
Generating 1 keys, please wait.
Abgeschlossen!
AUDITOR PUB is YD16NT1JD6FV0KVG0GQ5K3YW65ASQAQ6NFXFC0Y29XYRQ1EJZP30 using file /home/oec/projects/diss/code/exchange/src/auditor/generate_auditordb_home//.local/share/taler//auditor/offline-keys/auditor.priv
Setting up exchange
Setting up merchant
Setting up auditor
Launching services
.................... DONE
Setting up keys.. DONE
Adding auditor signatures ... DONE
Setting up merchant  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100   498  100   155  100   343   105k   234k --:--:-- --:--:-- --:--:--  486k
{
  "hint": "The JSON in the client's request was malformed (generic parse error).",
  "code": 22,
  "field": "default_wire_transfer_delay",
  "line": 12
} DONE
Running wallet
Shutting down services
Dumping database
Final clean up
=====================================
  Finished generation of /tmp/taler-auditor-basedbCWOgB9/basedb
=====================================
Running test suite with database /tmp/taler-auditor-basedbCWOgB9/basedb using configuration auditor-basedb.conf
Calculating database age based on /tmp/taler-auditor-basedbCWOgB9/basedb.age
Database age is 0 seconds
Doing full reload of the database... DONE
===========0: normal run with aggregator===========
Launching bank ........................ DONE
Running exchange aggregator ... DONE
Running exchange closer ... DONE
Running exchange transfer ... DONE
Running audit(s) ............. DONE
TeXing ... DONE
Checking output
Test for emergencies... PASS
Test for deposit confirmation emergencies... PASS
Test for emergencies by count... PASS
Test for wire inconsistencies... PASS
Test for wire amounts... PASS
Checking for unexpected arithmetic differences PASS
Checking for unexpected wire out differences PASS
Doing full reload of the database... DONE
===========1: normal run===========
Launching bank ....................... DONE
Running audit(s) ............. DONE
TeXing ... DONE
Checking output
Test for emergencies... PASS
Test for emergencies by count... PASS
Test for wire inconsistencies... PASS
Check for lag detection... SKIP (database too new)
Test for wire amounts... OK
===========2: reserves_in inconsistency===========
UPDATE 1
Launching bank ....................... DONE
Running audit(s) ............. DONE
TeXing ... DONE
Testing inconsistency detection... PASS
===========3: reserves_in inconsistency===========
Launching bank ...................... DONE
Running audit(s) ............. DONE
TeXing ... DONE
===========4: deposit wire target wrong=================
ERROR:  syntax error at or near ";"
LINE 1: ... wire_target_h_payto FROM deposits WHERE deposit_serial_id=;
                                                                      ^
ERROR:  syntax error at end of input
LINE 1: ...db42d45b721ffc4eb1e5b9ddaf1565660b' WHERE deposit_serial_id=
                                                                       ^
Launching bank ...................... DONE
Running audit(s) ............. DONE
TeXing ... DONE
Testing inconsistency detection... Bad signature not detected
FAIL test-auditor.sh (exit status: 1)

FAIL: test-revocation.sh
========================

Testing for jq
Testing for taler-bank-manage
Testing for pdflatex
Testing for taler-wallet-cli FOUND. Generating fresh database at /tmp/taler-auditor-basedbl3ph9U
Testing for taler-bank-manage FOUND
Testing for taler-wallet-cli FOUND
Testing for curl FOUND
Generating 1 keys, please wait.
Abgeschlossen!
Generating 1 keys, please wait.
Abgeschlossen!
Setting up exchange
Setting up merchant
Setting up auditor
Launching services
..................... DONE
Setting up keys.. DONE
Setting up merchant  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100   501  100   155  100   346   109k   243k --:--:-- --:--:-- --:--:--  489k
{
  "hint": "The JSON in the client's request was malformed (generic parse error).",
  "code": 22,
  "field": "default_wire_transfer_delay",
  "line": 12
}Running wallet
2022-07-22T11:08:31.731Z query.ts INFO handling live db version change from 0 to 1
2022-07-22T11:08:31.763Z taler-wallet-cli.ts INFO handling 'api' request (withdrawTestBalance)
2022-07-22T11:08:32.050Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:08:32.069Z exchanges.ts INFO updating exchange /keys info
2022-07-22T11:08:32.167Z exchanges.ts INFO updating exchange /wire info
2022-07-22T11:08:32.195Z exchanges.ts INFO validating exchange /wire info
2022-07-22T11:08:32.390Z exchanges.ts INFO finished validating exchange /wire info
2022-07-22T11:08:32.402Z exchanges.ts INFO updating denominations in database
2022-07-22T11:08:34.986Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:08:35.069Z exchanges.ts INFO using existing exchange info
2022-07-22T11:08:35.225Z taler-wallet-core:reserves.ts INFO Withdrawal operation not yet confirmed by bank
2022-07-22T11:08:35.249Z taler-wallet-core:reserves.ts INFO Withdrawal operation not yet confirmed by bank
2022-07-22T11:08:35.276Z taler-wallet-core:reserves.ts INFO Withdrawal operation not yet confirmed by bank
2022-07-22T11:08:35.302Z taler-wallet-core:reserves.ts INFO Withdrawal operation not yet confirmed by bank
{
  "type": "response",
  "operation": "withdrawTestBalance",
  "id": "reqid-1",
  "result": {}
}
2022-07-22T11:08:35.434Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:35.435Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:08:35.435Z taler-wallet-cli.ts INFO finished handling API request
2022-07-22T11:08:35.753Z taler-wallet-cli.ts INFO running until pending operations are finished
2022-07-22T11:08:35.795Z refresh.ts INFO doing auto-refresh check for 'http://localhost:8081/'
2022-07-22T11:08:35.795Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: true
2022-07-22T11:08:35.866Z exchanges.ts INFO updating exchange /keys info
2022-07-22T11:08:35.943Z exchanges.ts INFO updating exchange /wire info
2022-07-22T11:08:35.947Z exchanges.ts INFO validating exchange /wire info
2022-07-22T11:08:36.115Z exchanges.ts INFO finished validating exchange /wire info
2022-07-22T11:08:36.128Z exchanges.ts INFO updating denominations in database
2022-07-22T11:08:37.960Z refresh.ts INFO current wallet time: 2022-07-22T11:08:37.960Z
2022-07-22T11:08:37.960Z refresh.ts INFO next refresh check at 2022-07-23T11:08:37.954Z
2022-07-22T11:08:38.016Z taler-wallet-core:reserves.ts INFO querying reserve status via http://localhost:8081/reserves/A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0?timeout_ms=30000
2022-07-22T11:08:38.086Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:08:38.133Z exchanges.ts INFO using existing exchange info
2022-07-22T11:08:38.750Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/0
2022-07-22T11:08:38.767Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/1
2022-07-22T11:08:38.778Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/2
2022-07-22T11:08:38.813Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/3
2022-07-22T11:08:38.854Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/4
2022-07-22T11:08:38.883Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/5
2022-07-22T11:08:38.914Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/6
2022-07-22T11:08:38.946Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/7
2022-07-22T11:08:38.981Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/8
2022-07-22T11:08:39.013Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/9
2022-07-22T11:08:39.050Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/10
2022-07-22T11:08:39.085Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/11
2022-07-22T11:08:39.122Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/12
2022-07-22T11:08:39.160Z operations/withdraw.ts INFO processing planchet exchange request A4Z5VG05FF1284PEK4T7YP0B1FKB5ZECN2WJV63PHWH51FCED990/13
2022-07-22T11:08:39.339Z wallet.ts WARN stopping, as no pending operations have lifeness
2022-07-22T11:08:39.340Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:39.340Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:08:39.671Z wallet.ts INFO dumping coins
2022-07-22T11:08:39.732Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:39.732Z taler-wallet-cli.ts INFO stopped wallet
COINS are:{ "coins": [ { "coin_pub": "30WA5WJJ9A3BSB2HADCSFVBH6WPCCY5YNVR5QNWD7X4J4N8T77J0", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000Z16W73FTRMMNA21MZEV089XG1NFBE3VQ28MS88VTJEQPA025R5ST34XMDH91QHFBX13QSD44FJRG4NTX34F8YPQ2J87XY5HSYHWQP9M58THSJ3E2VJRRJG3ZTGHKP8ZAENBPE0ZB0JJ9DG5RMYJ6MD9A0NSHB5CJYBWBT279JVJTCW5V2TQQE260DKRM6BCWV6EPRDKSG8E23G2001", "age_mask": 0 }, "denom_pub_hash": "D0616MFEVWFGD3KJVMY50EK0WZRDEPF2EFAPBSVQFYQB9B0FCR5SE58QVP0HYW0Y4YWPXSQP5XM915P351G1CZCPT6S8N4Q4JV56B98", "denom_value": "TESTKUDOS:0.01", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.01", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "A4W68CFC2V1Y26P8B5XBGVBY9XTPCJD63J4PR39W7RKHE6PDT140", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000XFWN4HZ83A8HP8PPHGEVCGF6X4VJVQZ8JF6KAXND14BAMP6ZBD7201VG8Q2X4TAMV46DFJ197VDMM5KHPAKBH9PRHS57W699WVKR2R2B5X9GMGRHPTYHFJVYGC6C26CEPXHT57RP0XQRC7Y1NACHXHCNK1ZV9VW0P0Q2PVSQWW3J5BRG2RWZRFPB5TYMEV43ZHZRZDQSX9NNTG2001", "age_mask": 0 }, "denom_pub_hash": "AJ5TDNFQY3K71WA03A9FVJ7V5BANRNPJ97H1B8YKD74TWSJ6T3A37C3Q3BNVCRE2STNBYWDQXDKKT5FRK2QVREZVWX634V6CZ9VAGH8", "denom_value": "TESTKUDOS:0.1", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.1", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "BNFRP8KGCY73C3EA81FYN84PBQGS5284314651XCCHBJTKWGEN00", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000YXW4WMPZAYXFX5HGAP9G9PPARFVMQE0SB55PXAWHQQDV0Q7NKRCKCDB9B4ZPDZC4Z3PX5PCP93A8AMHDASW0VC6E9SYG29AW4XG5A226XY9P15HFBCHPJWHTHWX2416JZJYTK7TCZTMWQY8X59S0GCA0Z9JVKG4VWBBAR5EQK4E2XYZXF37KTWR486VA8075W7HE7XDEVXRM6G2001", "age_mask": 0 }, "denom_pub_hash": "71GCEZAP4TJ33T01SK1MSQTR52A3AK948AW6ESK5MZ44K228MFQ3FXNG29CQHCN3K2ZHEYXXSRPHPPBZ9TKAWP1QR5C0375S51QMKJR", "denom_value": "TESTKUDOS:2", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:2", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "C7WABZ7W07WGJVXJ58VCTAPZX64VGMDX7EFRESSNV54QHVPWBRW0", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000XFWN4HZ83A8HP8PPHGEVCGF6X4VJVQZ8JF6KAXND14BAMP6ZBD7201VG8Q2X4TAMV46DFJ197VDMM5KHPAKBH9PRHS57W699WVKR2R2B5X9GMGRHPTYHFJVYGC6C26CEPXHT57RP0XQRC7Y1NACHXHCNK1ZV9VW0P0Q2PVSQWW3J5BRG2RWZRFPB5TYMEV43ZHZRZDQSX9NNTG2001", "age_mask": 0 }, "denom_pub_hash": "AJ5TDNFQY3K71WA03A9FVJ7V5BANRNPJ97H1B8YKD74TWSJ6T3A37C3Q3BNVCRE2STNBYWDQXDKKT5FRK2QVREZVWX634V6CZ9VAGH8", "denom_value": "TESTKUDOS:0.1", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.1", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "D7X1DNM1F5TFP0C8Y1P900YGXM76NEJVBHRBF26SZMZ3BJJ8HSE0", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000Z16W73FTRMMNA21MZEV089XG1NFBE3VQ28MS88VTJEQPA025R5ST34XMDH91QHFBX13QSD44FJRG4NTX34F8YPQ2J87XY5HSYHWQP9M58THSJ3E2VJRRJG3ZTGHKP8ZAENBPE0ZB0JJ9DG5RMYJ6MD9A0NSHB5CJYBWBT279JVJTCW5V2TQQE260DKRM6BCWV6EPRDKSG8E23G2001", "age_mask": 0 }, "denom_pub_hash": "D0616MFEVWFGD3KJVMY50EK0WZRDEPF2EFAPBSVQFYQB9B0FCR5SE58QVP0HYW0Y4YWPXSQP5XM915P351G1CZCPT6S8N4Q4JV56B98", "denom_value": "TESTKUDOS:0.01", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.01", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "FG7Z51V60CGB1SVVTT98B1D3AC812CQ9M81KV8DE79QPD441NWQG", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000XFWN4HZ83A8HP8PPHGEVCGF6X4VJVQZ8JF6KAXND14BAMP6ZBD7201VG8Q2X4TAMV46DFJ197VDMM5KHPAKBH9PRHS57W699WVKR2R2B5X9GMGRHPTYHFJVYGC6C26CEPXHT57RP0XQRC7Y1NACHXHCNK1ZV9VW0P0Q2PVSQWW3J5BRG2RWZRFPB5TYMEV43ZHZRZDQSX9NNTG2001", "age_mask": 0 }, "denom_pub_hash": "AJ5TDNFQY3K71WA03A9FVJ7V5BANRNPJ97H1B8YKD74TWSJ6T3A37C3Q3BNVCRE2STNBYWDQXDKKT5FRK2QVREZVWX634V6CZ9VAGH8", "denom_value": "TESTKUDOS:0.1", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.1", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "KCA1H6MWC8GBG5AFA1JH05WG3JHK45PA88KKNTP2CHC8V7JAM4QG", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000XFWN4HZ83A8HP8PPHGEVCGF6X4VJVQZ8JF6KAXND14BAMP6ZBD7201VG8Q2X4TAMV46DFJ197VDMM5KHPAKBH9PRHS57W699WVKR2R2B5X9GMGRHPTYHFJVYGC6C26CEPXHT57RP0XQRC7Y1NACHXHCNK1ZV9VW0P0Q2PVSQWW3J5BRG2RWZRFPB5TYMEV43ZHZRZDQSX9NNTG2001", "age_mask": 0 }, "denom_pub_hash": "AJ5TDNFQY3K71WA03A9FVJ7V5BANRNPJ97H1B8YKD74TWSJ6T3A37C3Q3BNVCRE2STNBYWDQXDKKT5FRK2QVREZVWX634V6CZ9VAGH8", "denom_value": "TESTKUDOS:0.1", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.1", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "KJ4XATERA319DJET4P61XJTPZ6V2QPP610B7F0694K85REBHYDZG", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000Z16W73FTRMMNA21MZEV089XG1NFBE3VQ28MS88VTJEQPA025R5ST34XMDH91QHFBX13QSD44FJRG4NTX34F8YPQ2J87XY5HSYHWQP9M58THSJ3E2VJRRJG3ZTGHKP8ZAENBPE0ZB0JJ9DG5RMYJ6MD9A0NSHB5CJYBWBT279JVJTCW5V2TQQE260DKRM6BCWV6EPRDKSG8E23G2001", "age_mask": 0 }, "denom_pub_hash": "D0616MFEVWFGD3KJVMY50EK0WZRDEPF2EFAPBSVQFYQB9B0FCR5SE58QVP0HYW0Y4YWPXSQP5XM915P351G1CZCPT6S8N4Q4JV56B98", "denom_value": "TESTKUDOS:0.01", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.01", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "M0K26Y8MJRW4BNST84RPEK56ZQGJTCH79B6YZKHKX4JBTG8B3AP0", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000XFWN4HZ83A8HP8PPHGEVCGF6X4VJVQZ8JF6KAXND14BAMP6ZBD7201VG8Q2X4TAMV46DFJ197VDMM5KHPAKBH9PRHS57W699WVKR2R2B5X9GMGRHPTYHFJVYGC6C26CEPXHT57RP0XQRC7Y1NACHXHCNK1ZV9VW0P0Q2PVSQWW3J5BRG2RWZRFPB5TYMEV43ZHZRZDQSX9NNTG2001", "age_mask": 0 }, "denom_pub_hash": "AJ5TDNFQY3K71WA03A9FVJ7V5BANRNPJ97H1B8YKD74TWSJ6T3A37C3Q3BNVCRE2STNBYWDQXDKKT5FRK2QVREZVWX634V6CZ9VAGH8", "denom_value": "TESTKUDOS:0.1", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.1", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "PBN7DM79YAYV0448WNT0WWSRAECATHA45WJJ16DKPHWATQFP7HG0", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000YCRRY63X4TZ0W6K0TSK4MZCYTDW61754CZN5YEJ36AP2BBZ10B7MTT3FDD7E12100NHYRWVSYZWF6W2EQANDT9Q2X327EZ5GE31R6QKY48FVTKWXR7N988JV714E6J2RH07MD7WPBHCMY5X36K529VMH02BF5Q2330K7Q1PFB0SR48W6YHFJ7DGPR9GQ7HD8JAZZ3KAT8XS90G2001", "age_mask": 0 }, "denom_pub_hash": "8RMGQJ731GZ4M6ADBX5FQ3WF3HMJJSQA7MG29ZEN27YGGDMGMQDQT42RD8ZNZ23AFTWSJPAK0R9XQGVPMX602Q1ZJVY1C3CAPN4W5S0", "denom_value": "TESTKUDOS:5", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:5", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "T0M9E3CYYV6YRH7M8C9E7JM3VA3CAKXR7EMRX81B2ND8YG14MZJ0", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000XFWN4HZ83A8HP8PPHGEVCGF6X4VJVQZ8JF6KAXND14BAMP6ZBD7201VG8Q2X4TAMV46DFJ197VDMM5KHPAKBH9PRHS57W699WVKR2R2B5X9GMGRHPTYHFJVYGC6C26CEPXHT57RP0XQRC7Y1NACHXHCNK1ZV9VW0P0Q2PVSQWW3J5BRG2RWZRFPB5TYMEV43ZHZRZDQSX9NNTG2001", "age_mask": 0 }, "denom_pub_hash": "AJ5TDNFQY3K71WA03A9FVJ7V5BANRNPJ97H1B8YKD74TWSJ6T3A37C3Q3BNVCRE2STNBYWDQXDKKT5FRK2QVREZVWX634V6CZ9VAGH8", "denom_value": "TESTKUDOS:0.1", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.1", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "VSPH4A7AVRBTA00CPG3F50YRKE0C28HYXJFW2M5MPQY0CK2P925G", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000XFWN4HZ83A8HP8PPHGEVCGF6X4VJVQZ8JF6KAXND14BAMP6ZBD7201VG8Q2X4TAMV46DFJ197VDMM5KHPAKBH9PRHS57W699WVKR2R2B5X9GMGRHPTYHFJVYGC6C26CEPXHT57RP0XQRC7Y1NACHXHCNK1ZV9VW0P0Q2PVSQWW3J5BRG2RWZRFPB5TYMEV43ZHZRZDQSX9NNTG2001", "age_mask": 0 }, "denom_pub_hash": "AJ5TDNFQY3K71WA03A9FVJ7V5BANRNPJ97H1B8YKD74TWSJ6T3A37C3Q3BNVCRE2STNBYWDQXDKKT5FRK2QVREZVWX634V6CZ9VAGH8", "denom_value": "TESTKUDOS:0.1", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.1", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "W1EFQ99XW91H1QWP9RKNEYBXWC4XFYSTCV7DW5BZ47XP8VNZBFEG", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000XFWN4HZ83A8HP8PPHGEVCGF6X4VJVQZ8JF6KAXND14BAMP6ZBD7201VG8Q2X4TAMV46DFJ197VDMM5KHPAKBH9PRHS57W699WVKR2R2B5X9GMGRHPTYHFJVYGC6C26CEPXHT57RP0XQRC7Y1NACHXHCNK1ZV9VW0P0Q2PVSQWW3J5BRG2RWZRFPB5TYMEV43ZHZRZDQSX9NNTG2001", "age_mask": 0 }, "denom_pub_hash": "AJ5TDNFQY3K71WA03A9FVJ7V5BANRNPJ97H1B8YKD74TWSJ6T3A37C3Q3BNVCRE2STNBYWDQXDKKT5FRK2QVREZVWX634V6CZ9VAGH8", "denom_value": "TESTKUDOS:0.1", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.1", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false }, { "coin_pub": "WJM3BQHV8336FB8J917K2VQ5F5BKAQSKN9K9ZJ0VHT8RJAFFQYVG", "denom_pub": { "cipher": "RSA", "rsa_public_key": "020000Z16W73FTRMMNA21MZEV089XG1NFBE3VQ28MS88VTJEQPA025R5ST34XMDH91QHFBX13QSD44FJRG4NTX34F8YPQ2J87XY5HSYHWQP9M58THSJ3E2VJRRJG3ZTGHKP8ZAENBPE0ZB0JJ9DG5RMYJ6MD9A0NSHB5CJYBWBT279JVJTCW5V2TQQE260DKRM6BCWV6EPRDKSG8E23G2001", "age_mask": 0 }, "denom_pub_hash": "D0616MFEVWFGD3KJVMY50EK0WZRDEPF2EFAPBSVQFYQB9B0FCR5SE58QVP0HYW0Y4YWPXSQP5XM915P351G1CZCPT6S8N4Q4JV56B98", "denom_value": "TESTKUDOS:0.01", "exchange_base_url": "http://localhost:8081/", "remaining_value": "TESTKUDOS:0.01", "withdrawal_reserve_pub": "A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0", "coin_suspended": false } ] }
Revoking denomination 71GCEZAP4TJ33T01SK1MSQTR52A3AK948AW6ESK5MZ44K228MFQ3FXNG29CQHCN3K2ZHEYXXSRPHPPBZ9TKAWP1QR5C0375S51QMKJR (to affect coin BNFRP8KGCY73C3EA81FYN84PBQGS5284314651XCCHBJTKWGEN00)
2022-07-22T11:08:43.460Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:43.461Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:08:43.764Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: true
2022-07-22T11:08:43.844Z exchanges.ts INFO updating exchange /keys info
2022-07-22T11:08:43.921Z exchanges.ts INFO updating exchange /wire info
2022-07-22T11:08:43.948Z exchanges.ts INFO validating exchange /wire info
2022-07-22T11:08:44.136Z exchanges.ts INFO finished validating exchange /wire info
2022-07-22T11:08:44.156Z exchanges.ts INFO updating denominations in database
2022-07-22T11:08:45.017Z exchanges.ts INFO setting denomination 71GCEZAP4TJ33T01SK1MSQTR52A3AK948AW6ESK5MZ44K228MFQ3FXNG29CQHCN3K2ZHEYXXSRPHPPBZ9TKAWP1QR5C0375S51QMKJR to offered=false
2022-07-22T11:08:45.894Z exchanges.ts INFO revoking denom [
  "71GCEZAP4TJ33T01SK1MSQTR52A3AK948AW6ESK5MZ44K228MFQ3FXNG29CQHCN3K2ZHEYXXSRPHPPBZ9TKAWP1QR5C0375S51QMKJR"
]
2022-07-22T11:08:45.899Z exchanges.ts INFO recouping coins [
  [
    "BNFRP8KGCY73C3EA81FYN84PBQGS5284314651XCCHBJTKWGEN00"
  ]
]
2022-07-22T11:08:45.952Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:45.953Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:08:46.005Z operations/recoup.ts WARN processRecoup failed: Error: Crypto API stopped
2022-07-22T11:08:46.005Z exchanges.ts ERROR error while recouping coins: [
  {}
]
2022-07-22T11:08:46.329Z taler-wallet-cli.ts INFO running until pending operations are finished
2022-07-22T11:08:46.387Z refresh.ts INFO doing auto-refresh check for 'http://localhost:8081/'
2022-07-22T11:08:46.387Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: true
2022-07-22T11:08:46.459Z exchanges.ts INFO updating exchange /keys info
2022-07-22T11:08:47.343Z exchanges.ts INFO updating exchange /wire info
2022-07-22T11:08:47.351Z exchanges.ts INFO validating exchange /wire info
2022-07-22T11:08:47.552Z exchanges.ts INFO finished validating exchange /wire info
2022-07-22T11:08:47.570Z exchanges.ts INFO updating denominations in database
2022-07-22T11:08:49.401Z refresh.ts INFO current wallet time: 2022-07-22T11:08:49.401Z
2022-07-22T11:08:49.401Z refresh.ts INFO next refresh check at 2022-07-23T11:08:49.376Z
2022-07-22T11:08:49.517Z operations/recoup.ts INFO all recoups of recoup group are finished
2022-07-22T11:08:49.613Z taler-wallet-core:reserves.ts INFO querying reserve status via http://localhost:8081/reserves/A668SN7GCE1TADE3GHW7AMYKYJ7H10Y337TDYGS394KRBP5MQ2D0?timeout_ms=30000
2022-07-22T11:08:49.699Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:08:49.753Z exchanges.ts INFO using existing exchange info
2022-07-22T11:08:50.321Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/0
2022-07-22T11:08:50.331Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/1
2022-07-22T11:08:50.344Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/2
2022-07-22T11:08:50.377Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/3
2022-07-22T11:08:50.414Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/4
2022-07-22T11:08:50.463Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/5
2022-07-22T11:08:50.496Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/6
2022-07-22T11:08:50.536Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/7
2022-07-22T11:08:50.574Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/8
2022-07-22T11:08:50.689Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/9
2022-07-22T11:08:50.735Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/10
2022-07-22T11:08:50.785Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:08:50.848Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/11
2022-07-22T11:08:50.876Z exchanges.ts INFO using existing exchange info
2022-07-22T11:08:50.913Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/12
2022-07-22T11:08:50.991Z operations/withdraw.ts INFO processing planchet exchange request A0GC3EWGJTDMYYQQQ659RM8CPW08DFFC183ZVQSH5RQTYNKTC9Q0/13
2022-07-22T11:08:51.212Z wallet.ts WARN stopping, as no pending operations have lifeness
2022-07-22T11:08:51.213Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:51.213Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:08:51.610Z taler-wallet-cli.ts INFO handling 'api' request (testPay)
2022-07-22T11:08:51.627Z wallet.ts INFO finished wallet core request with error: {
  "code": 7005,
  "hint": "Unexpected HTTP status 404 in response",
  "requestUrl": "http://localhost:9966/private/orders",
  "httpStatusCode": 404,
  "errorResponse": {
    "code": 2000,
    "hint": "The backend could not find the merchant instance specified in the request."
  }
}
{
  "type": "error",
  "operation": "testPay",
  "id": "reqid-1",
  "error": {
    "code": 7005,
    "hint": "Unexpected HTTP status 404 in response",
    "requestUrl": "http://localhost:9966/private/orders",
    "httpStatusCode": 404,
    "errorResponse": {
      "code": 2000,
      "hint": "The backend could not find the merchant instance specified in the request."
    }
  }
}
2022-07-22T11:08:51.628Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:51.628Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:08:51.628Z taler-wallet-cli.ts INFO finished handling API request
2022-07-22T11:08:51.954Z taler-wallet-cli.ts INFO running until pending operations are finished
2022-07-22T11:08:52.057Z wallet.ts WARN stopping, as no pending operations have lifeness
2022-07-22T11:08:52.057Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:52.057Z taler-wallet-cli.ts INFO stopped wallet
Purchase with recoup'ed coin (via reserve) done
Will refresh coin PBN7DM79YAYV0448WNT0WWSRAECATHA45WJJ16DKPHWATQFP7HG0 of denomination 8RMGQJ731GZ4M6ADBX5FQ3WF3HMJJSQA7MG29ZEN27YGGDMGMQDQT42RD8ZNZ23AFTWSJPAK0R9XQGVPMX602Q1ZJVY1C3CAPN4W5S0
Launching exchange 1 week in the future
.Refreshing coin PBN7DM79YAYV0448WNT0WWSRAECATHA45WJJ16DKPHWATQFP7HG0
2022-07-22T11:08:52.461Z taler-wallet-cli.ts INFO timetravelling 604800000000 microseconds
2022-07-22T11:08:53.132Z refresh.ts INFO created refresh group BK4X7G5JHGBW5N41GSH1PP1YVD4RRMH44G04D0GX2E2YNKEFZFJ0
2022-07-22T11:08:53.133Z refresh.ts INFO processing refresh group BK4X7G5JHGBW5N41GSH1PP1YVD4RRMH44G04D0GX2E2YNKEFZFJ0
2022-07-22T11:08:53.206Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:53.206Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:08:53.243Z refresh.ts INFO processing refresh session for coin 0 of group BK4X7G5JHGBW5N41GSH1PP1YVD4RRMH44G04D0GX2E2YNKEFZFJ0
2022-07-22T11:08:53.274Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:08:53.332Z exchanges.ts INFO updating exchange /keys info
2022-07-22T11:08:54.356Z exchanges.ts INFO updating exchange /wire info
2022-07-22T11:08:54.387Z exchanges.ts INFO validating exchange /wire info
2022-07-22T11:08:54.388Z refresh.ts INFO crypto API stopped while processing refresh group, probably the wallet is currently shutting down.
2022-07-22T11:08:54.524Z taler-wallet-cli.ts INFO timetravelling 604800000000 microseconds
2022-07-22T11:08:54.711Z taler-wallet-cli.ts INFO running until pending operations are finished
2022-07-22T11:08:54.772Z refresh.ts INFO doing auto-refresh check for 'http://localhost:8081/'
2022-07-22T11:08:54.773Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: true
2022-07-22T11:08:54.848Z exchanges.ts INFO updating exchange /keys info
2022-07-22T11:08:55.784Z exchanges.ts INFO updating exchange /wire info
2022-07-22T11:08:55.791Z exchanges.ts INFO validating exchange /wire info
2022-07-22T11:08:55.965Z exchanges.ts INFO finished validating exchange /wire info
2022-07-22T11:08:55.981Z exchanges.ts INFO updating denominations in database
2022-07-22T11:08:57.807Z refresh.ts INFO current wallet time: 2022-07-29T11:08:57.807Z
2022-07-22T11:08:57.807Z refresh.ts INFO next refresh check at 2022-07-30T11:08:57.749Z
2022-07-22T11:08:57.849Z refresh.ts INFO processing refresh group BK4X7G5JHGBW5N41GSH1PP1YVD4RRMH44G04D0GX2E2YNKEFZFJ0
2022-07-22T11:08:57.884Z refresh.ts INFO processing refresh session for coin 0 of group BK4X7G5JHGBW5N41GSH1PP1YVD4RRMH44G04D0GX2E2YNKEFZFJ0
2022-07-22T11:08:57.910Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:08:57.972Z exchanges.ts INFO using existing exchange info
2022-07-22T11:08:58.519Z refresh.ts INFO created refresh session for coin #0 in BK4X7G5JHGBW5N41GSH1PP1YVD4RRMH44G04D0GX2E2YNKEFZFJ0
2022-07-22T11:08:58.955Z refresh.ts INFO doing refresh reveal
2022-07-22T11:08:59.660Z wallet.ts WARN stopping, as no pending operations have lifeness
2022-07-22T11:08:59.661Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:08:59.661Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:08:59.798Z taler-wallet-cli.ts INFO timetravelling 604800000000 microseconds
2022-07-22T11:08:59.975Z wallet.ts INFO dumping coins
2022-07-22T11:09:00.123Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:09:00.123Z taler-wallet-cli.ts INFO stopped wallet
Coin 0PR7KF8ZT13NB4W45G56CGCANYMNF9WFX0S6J49WNXT3WZWA5D50 of denomination SCQ563M6FTWHSAVJJN4HCSR9QMNQVPNZTYS5JN9V3KTQKNS838BAAC4AZFNEAQ5T1FNDAWGESJX8MXXKJTM1Y5EJHRGY3M8BFR98QPG is the result of the refresh
Revoking SCQ563M6FTWHSAVJJN4HCSR9QMNQVPNZTYS5JN9V3KTQKNS838BAAC4AZFNEAQ5T1FNDAWGESJX8MXXKJTM1Y5EJHRGY3M8BFR98QPG (to affect coin 0PR7KF8ZT13NB4W45G56CGCANYMNF9WFX0S6J49WNXT3WZWA5D50)
2022-07-22T11:09:03.406Z taler-wallet-cli.ts INFO timetravelling 604800000000 microseconds
2022-07-22T11:09:04.713Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:09:04.714Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:09:04.849Z taler-wallet-cli.ts INFO timetravelling 604800000000 microseconds
2022-07-22T11:09:05.026Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: true
2022-07-22T11:09:05.118Z exchanges.ts INFO updating exchange /keys info
2022-07-22T11:09:05.192Z exchanges.ts INFO updating exchange /wire info
2022-07-22T11:09:05.220Z exchanges.ts INFO validating exchange /wire info
2022-07-22T11:09:05.419Z exchanges.ts INFO finished validating exchange /wire info
2022-07-22T11:09:05.435Z exchanges.ts INFO updating denominations in database
2022-07-22T11:09:06.947Z exchanges.ts INFO setting denomination SCQ563M6FTWHSAVJJN4HCSR9QMNQVPNZTYS5JN9V3KTQKNS838BAAC4AZFNEAQ5T1FNDAWGESJX8MXXKJTM1Y5EJHRGY3M8BFR98QPG to offered=false
2022-07-22T11:09:07.205Z exchanges.ts INFO revoking denom [
  "SCQ563M6FTWHSAVJJN4HCSR9QMNQVPNZTYS5JN9V3KTQKNS838BAAC4AZFNEAQ5T1FNDAWGESJX8MXXKJTM1Y5EJHRGY3M8BFR98QPG"
]
2022-07-22T11:09:07.217Z exchanges.ts INFO recouping coins [
  [
    "0PR7KF8ZT13NB4W45G56CGCANYMNF9WFX0S6J49WNXT3WZWA5D50",
    "1SAM9H811RKBRM6W37MDQ2BKVVY3CGW0WTY4MPMV7ZC8ZJ6DYAWG",
    "3GDEE54FSHC4E31WZJ760W50FP5EPY8ZSZJPC7HJH3H6GDA5TXE0",
    "9RP2CEG6HMSST20B0SYWBM138X5NSGPWS87X66Y11V9FRXMWJ2DG",
    "D588X5C9M4RF4Q35CM5WPMQF418CKJFZ3Q3YXVFJQPXGDHV60WSG",
    "E5MMDZZ0KMPG9CXXM18KJPX53J6BZ0C7ZJVSGKAH8WWFR4R48PY0",
    "GB84TVAK4PXZFNNV5XB6V572W9NEJ58ZGE9C4MWJTVZRCHHRTEV0",
    "JVNB1HKB36WPXSW4G5JWZP830V8WBQVFYBNM3JWW5QN3JW3WPQTG"
  ]
]
2022-07-22T11:09:07.296Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:09:07.296Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:09:07.366Z operations/recoup.ts WARN processRecoup failed: Error: Crypto API stopped
2022-07-22T11:09:07.367Z exchanges.ts ERROR error while recouping coins: [
  {}
]
2022-07-22T11:09:07.367Z operations/recoup.ts WARN processRecoup failed: Error: Crypto API stopped
2022-07-22T11:09:07.368Z operations/recoup.ts WARN processRecoup failed: Error: Crypto API stopped
2022-07-22T11:09:07.370Z operations/recoup.ts WARN processRecoup failed: Error: Crypto API stopped
2022-07-22T11:09:07.371Z operations/recoup.ts WARN processRecoup failed: Error: Crypto API stopped
2022-07-22T11:09:07.373Z operations/recoup.ts WARN processRecoup failed: Error: Crypto API stopped
2022-07-22T11:09:07.374Z operations/recoup.ts WARN processRecoup failed: Error: Crypto API stopped
2022-07-22T11:09:07.375Z operations/recoup.ts WARN processRecoup failed: Error: Crypto API stopped
2022-07-22T11:09:07.508Z taler-wallet-cli.ts INFO timetravelling 604800000000 microseconds
2022-07-22T11:09:07.661Z taler-wallet-cli.ts INFO running until pending operations are finished
2022-07-22T11:09:07.716Z refresh.ts INFO doing auto-refresh check for 'http://localhost:8081/'
2022-07-22T11:09:07.716Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: true
2022-07-22T11:09:07.787Z exchanges.ts INFO updating exchange /keys info
2022-07-22T11:09:08.698Z exchanges.ts INFO updating exchange /wire info
2022-07-22T11:09:08.704Z exchanges.ts INFO validating exchange /wire info
2022-07-22T11:09:08.863Z exchanges.ts INFO finished validating exchange /wire info
2022-07-22T11:09:08.879Z exchanges.ts INFO updating denominations in database
2022-07-22T11:09:10.746Z refresh.ts INFO current wallet time: 2022-07-29T11:09:10.746Z
2022-07-22T11:09:10.746Z refresh.ts INFO next refresh check at 2022-07-30T11:09:10.689Z
2022-07-22T11:09:11.293Z operations/recoup.ts INFO all recoups of recoup group are finished
2022-07-22T11:09:11.844Z refresh.ts INFO created refresh group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.845Z refresh.ts INFO processing refresh group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.944Z refresh.ts INFO processing refresh session for coin 0 of group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.944Z refresh.ts INFO processing refresh session for coin 1 of group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.945Z refresh.ts INFO processing refresh session for coin 2 of group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.945Z refresh.ts INFO processing refresh session for coin 3 of group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.945Z refresh.ts INFO processing refresh session for coin 4 of group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.945Z refresh.ts INFO processing refresh session for coin 5 of group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.945Z refresh.ts INFO processing refresh session for coin 6 of group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.945Z refresh.ts INFO processing refresh session for coin 7 of group 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:11.985Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:09:12.016Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:09:12.047Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:09:12.087Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:09:12.117Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:09:12.144Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:09:12.170Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:09:12.198Z exchanges.ts INFO updating exchange info for http://localhost:8081/, forced: false
2022-07-22T11:09:12.482Z exchanges.ts INFO using existing exchange info
2022-07-22T11:09:12.515Z exchanges.ts INFO using existing exchange info
2022-07-22T11:09:12.547Z exchanges.ts INFO using existing exchange info
2022-07-22T11:09:12.579Z exchanges.ts INFO using existing exchange info
2022-07-22T11:09:12.608Z exchanges.ts INFO using existing exchange info
2022-07-22T11:09:12.636Z exchanges.ts INFO using existing exchange info
2022-07-22T11:09:12.664Z exchanges.ts INFO using existing exchange info
2022-07-22T11:09:12.692Z exchanges.ts INFO using existing exchange info
2022-07-22T11:09:16.892Z refresh.ts INFO created refresh session for coin #0 in 626XTMQ4ERVQ4Y992WN69XQ5YYX65GFH00CMCETSV9FPF5RVSRJ0
2022-07-22T11:09:18.091Z refresh.ts INFO doing refresh reveal
2022-07-22T11:09:19.992Z wallet.ts WARN stopping, as no pending operations have lifeness
2022-07-22T11:09:19.993Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:09:19.993Z taler-wallet-cli.ts INFO stopped wallet
Restarting merchant (so new keys are known)
...2022-07-22T11:09:20.829Z taler-wallet-cli.ts INFO timetravelling 604800000000 microseconds
2022-07-22T11:09:21.031Z taler-wallet-cli.ts INFO handling 'api' request (testPay)
2022-07-22T11:09:21.062Z wallet.ts INFO finished wallet core request with error: {
  "code": 7005,
  "hint": "Unexpected HTTP status 404 in response",
  "requestUrl": "http://localhost:9966/private/orders",
  "httpStatusCode": 404,
  "errorResponse": {
    "code": 2000,
    "hint": "The backend could not find the merchant instance specified in the request."
  }
}
{
  "type": "error",
  "operation": "testPay",
  "id": "reqid-1",
  "error": {
    "code": 7005,
    "hint": "Unexpected HTTP status 404 in response",
    "requestUrl": "http://localhost:9966/private/orders",
    "httpStatusCode": 404,
    "errorResponse": {
      "code": 2000,
      "hint": "The backend could not find the merchant instance specified in the request."
    }
  }
}
2022-07-22T11:09:21.062Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:09:21.063Z taler-wallet-cli.ts INFO stopped wallet
2022-07-22T11:09:21.063Z taler-wallet-cli.ts INFO finished handling API request
2022-07-22T11:09:21.199Z taler-wallet-cli.ts INFO timetravelling 604800000000 microseconds
2022-07-22T11:09:21.401Z taler-wallet-cli.ts INFO running until pending operations are finished
2022-07-22T11:09:21.507Z wallet.ts WARN stopping, as no pending operations have lifeness
2022-07-22T11:09:21.508Z taler-wallet-cli.ts INFO operation with wallet finished, stopping
2022-07-22T11:09:21.508Z taler-wallet-cli.ts INFO stopped wallet
Bought something with refresh-recouped coin
Shutting down services
Dumping database
Final clean up
=====================================
  Finished revocation DB generation  
=====================================
Running test suite with database /tmp/taler-auditor-basedbl3ph9U/basedb using configuration revoke-basedb.conf
Calculating database age based on /tmp/taler-auditor-basedbl3ph9U/basedb.age
Database age is 1 seconds
Doing full reload of the database... DONE
===========0: normal run with aggregator===========
Launching bank ....................... DONE
Running exchange aggregator ... DONE
Running exchange closer ... DONE
Running exchange transfer ... DONE
Running audit(s) ............. DONE
Cleanup ... DONE
TeXing ... DONE
Checking output
Test for emergencies... PASS
Test for deposit confirmation emergencies... PASS
Test for emergencies by count... PASS
Test for wire inconsistencies... PASS
Test for wire amounts... PASS
Checking for unexpected arithmetic differences PASS
Checking for unexpected wire out differences PASS
Doing full reload of the database... DONE
===========1: normal run===========
Launching bank ........................ DONE
Running audit(s) ............. DONE
Cleanup ... DONE
TeXing ... DONE
Checking output
Test for emergencies... PASS
Test for emergencies by count... PASS
Test for wire inconsistencies... PASS
Test for wire amounts... OK
===========2: recoup amount inconsistency===========
Launching bank ...................... DONE
Running audit(s) ............. DONE
Cleanup ... DONE
TeXing ... DONE
Testing inconsistency detection... OK
===========3: recoup-refresh amount inconsistency===========
Launching bank ...................... DONE
Running audit(s) ............. DONE
Cleanup ... DONE
TeXing ... DONE
Testing inconsistency detection... OK
===========4: invalid recoup===========
Launching bank ....................... DONE
Running audit(s) ............. DONE
Cleanup ... DONE
TeXing ... DONE
Testing inconsistency detection... OK
Doing full reload of the database... DONE
Cleaning up /tmp/taler-auditor-basedbl3ph9U...
Running test suite with database revoke-basedb using configuration revoke-basedb.conf
Calculating database age based on revoke-basedb.age
Database age is 2847589 seconds
Doing full reload of the database... DONE
===========0: normal run with aggregator===========
Launching bank ....................... DONE
Running exchange aggregator ...FAIL
FAIL test-revocation.sh (exit status: 1)

FAIL: test-sync.sh
==================

Testing synchronization logic ......2022-07-22T13:10:25.462222+0200 pq-179167 ERROR PQprepare (`SELECT  reserve_found,balance_ok,nonce_ok,kycok AS kyc_ok,account_uuid AS payment_target_uuid,ruuid FROM exchange_do_withdraw ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10);' as `call_withdraw') failed with error: ERROR:  column "nonce_ok" does not exist
LINE 1: SELECT  reserve_found,balance_ok,nonce_ok,kycok AS kyc_ok,ac...
                                         ^

2022-07-22T13:10:25.462322+0200 taler-auditor-sync-179167 ERROR Failed to begin transaction with data source. Exiting
.FAIL
Record count mismatch: 424 / 0 in table denominations
FAIL test-sync.sh (exit status: 1)

test-suite.log (42,882 bytes)   

Christian Grothoff

2022-08-06 22:28

manager   ~0018990

should be better now, I get (sometimes) an error on test_34 of the test-auditor.sh, but the rest passes again.

Issue History

Date Modified Username Field Change
2022-07-20 18:38 oec New Issue
2022-07-20 18:38 oec Status new => assigned
2022-07-20 18:38 oec Assigned To => Christian Grothoff
2022-07-21 17:54 oec Note Added: 0018964
2022-07-22 12:59 oec Note Added: 0018969
2022-07-22 13:13 oec Note Added: 0018970
2022-07-22 13:13 oec File Added: test-suite.log
2022-07-22 13:13 oec Summary make check in auditor hangs => make check in auditor fails
2022-08-06 22:28 Christian Grothoff Note Added: 0018990
2022-08-09 15:37 Christian Grothoff Status assigned => resolved
2022-08-09 15:37 Christian Grothoff Resolution open => fixed
2022-08-09 15:37 Christian Grothoff Fixed in Version => 0.9
2022-08-09 15:37 Christian Grothoff Target Version => 0.9
2022-11-04 20:53 Christian Grothoff Status resolved => closed