From 7b20ee8c8d691c0d79403462411ec66c5ada36c4 Mon Sep 17 00:00:00 2001 From: Christian Grothoff Date: Mon, 26 Aug 2019 03:16:36 +0200 Subject: minor auditor report generation bugfixes: --- contrib/auditor-report.tex.j2 | 25 +++-- src/auditor/taler-auditor.c | 39 ++++---- src/auditor/taler-wire-auditor.c | 45 +++++---- src/auditor/test-auditor.sh | 147 ++++++++++++++++++++++++------ src/auditordb/plugin_auditordb_postgres.c | 22 ++++- 5 files changed, 194 insertions(+), 84 deletions(-) diff --git a/contrib/auditor-report.tex.j2 b/contrib/auditor-report.tex.j2 index 45b049f28..cbecf22e6 100644 --- a/contrib/auditor-report.tex.j2 +++ b/contrib/auditor-report.tex.j2 @@ -282,22 +282,21 @@ compromise resulting in proportional financial losses to the exchange. {\bf All withdrawals were covered by sufficient reserve funding.} {% else %} \begin{longtable}{p{4.5cm}|r} - {\bf Reserve} & \multicolumn{2}{|c|}{ {\bf Loss}} \\ \hline \hline + {\bf Reserve} & {\bf Loss} \\ \hline \hline \endfirsthead - {\bf Reserve} & \multicolumn{2}{|c|}{ {\bf Loss}} \\ \hline \hline + {\bf Reserve} & {\bf Loss} \\ \hline \hline \endhead \hline \hline - {\bf Reserve} & \multicolumn{2}{|c|}{ {\bf Loss}} + {\bf Reserve} & {\bf Loss} \endfoot \hline - {\bf Total loss} & & + {\bf Total loss} & {{ data.total_loss_balance_insufficient }} \\ \caption{Reserves with withdrawals higher than reserve funding.} \label{table:reserve:balance_insufficient} \endlastfoot {% for item in data.reserve_balance_insufficient_inconsistencies %} - \multicolumn{3}{l}{ {\tt {{ item.reserve_pub }} } } \\ -\nopagebreak + {\tt {{ item.reserve_pub }} } & {{ item.loss }} \\ \hline {% endfor %} @@ -436,16 +435,16 @@ incoming wire transfers does not match with that of the bank. {\bf All incoming wire transfer amounts and subjects matched up.} {% else %} \begin{longtable}{p{5.5cm}|r|r} - \multicolumn{5}{l}{ {\bf Wire transfer identifier} ({\bf Row}) } \\ + \multicolumn{2}{l}{ {\bf Wire transfer identifier} ({\bf Row}) } \\ {\bf Diagnostic} & {\bf Wired} & {\bf Expected} \\ \hline \hline \endfirsthead - \multicolumn{5}{l}{ {\bf Wire transfer identifier} ({\bf Row}) } \\ + \multicolumn{2}{l}{ {\bf Wire transfer identifier} ({\bf Row}) } \\ {\bf Diagnostic} & {\bf Wired} & {\bf Expected} \\ \hline \hline \endhead \hline \hline - \multicolumn{5}{l}{ {\bf Wire transfer identifier} ({\bf Row}) } \\ + \multicolumn{2}{l}{ {\bf Wire transfer identifier} ({\bf Row}) } \\ {\bf Diagnostic} & {\bf Wired} & {\bf Expected} \\ \endfoot \hline \hline @@ -456,14 +455,12 @@ incoming wire transfers does not match with that of the bank. \label{table:wire_in:transfer_amount_inconsistencies} \endlastfoot {% for item in wire.reserve_in_amount_inconsistencies %} - \multicolumn{5}{l}{ {\tt {{ item.wtid }} } ({{ item.row }}) } \\ + \multicolumn{2}{l}{ {\tt {{ item.wtid }} } ({{ item.row }}) } \\ \nopagebreak {{ item.timestamp }}: & {{ item.amount_wired }} & - {{ item.amount_expected }} \\ - {{ item.diagnostic }} & & & & \\ -%\nopagebreak -% & \multicolumn{4}{|c}{ {{ item.timestamp }} } + {{ item.amount_exchange_expected }} \\ + \multicolumn{3}{l}{ {{ item.diagnostic }} } \\ \hline {% endfor %} \end{longtable} diff --git a/src/auditor/taler-auditor.c b/src/auditor/taler-auditor.c index 536a5cabe..347f3af65 100644 --- a/src/auditor/taler-auditor.c +++ b/src/auditor/taler-auditor.c @@ -1384,6 +1384,7 @@ verify_reserve_balance (void *cls, struct ReserveSummary *rs = value; struct TALER_EXCHANGEDB_Reserve reserve; struct TALER_Amount balance; + struct TALER_Amount nbalance; enum GNUNET_DB_QueryStatus qs; int ret; @@ -1422,7 +1423,7 @@ verify_reserve_balance (void *cls, } if (GNUNET_SYSERR == - TALER_amount_subtract (&balance, + TALER_amount_subtract (&nbalance, &balance, &rs->total_out)) { @@ -1437,25 +1438,25 @@ verify_reserve_balance (void *cls, &total_balance_insufficient_loss, &loss)); report (report_reserve_balance_insufficient_inconsistencies, - json_pack ("{s:o, s:o, s:o, s:s}", + json_pack ("{s:o, s:o}", "reserve_pub", GNUNET_JSON_from_data_auto (&rs->reserve_pub), "loss", TALER_JSON_from_amount (&loss))); goto cleanup; } - if (0 != TALER_amount_cmp (&balance, + if (0 != TALER_amount_cmp (&nbalance, &reserve.balance)) { struct TALER_Amount delta; - if (0 < TALER_amount_cmp (&balance, + if (0 < TALER_amount_cmp (&nbalance, &reserve.balance)) { /* balance > reserve.balance */ GNUNET_assert (GNUNET_OK == TALER_amount_subtract (&delta, - &balance, + &nbalance, &reserve.balance)); GNUNET_assert (GNUNET_OK == TALER_amount_add (&total_balance_summary_delta_plus, @@ -1468,7 +1469,7 @@ verify_reserve_balance (void *cls, GNUNET_assert (GNUNET_OK == TALER_amount_subtract (&delta, &reserve.balance, - &balance)); + &nbalance)); GNUNET_assert (GNUNET_OK == TALER_amount_add (&total_balance_summary_delta_minus, &total_balance_summary_delta_minus, @@ -1481,7 +1482,7 @@ verify_reserve_balance (void *cls, "exchange", TALER_JSON_from_amount (&reserve.balance), "auditor", - TALER_JSON_from_amount (&balance))); + TALER_JSON_from_amount (&nbalance))); goto cleanup; } @@ -1489,19 +1490,19 @@ verify_reserve_balance (void *cls, if ( (CLOSING_GRACE_PERIOD.rel_value_us > GNUNET_TIME_absolute_get_duration ( rs->a_expiration_date).rel_value_us) && - ( (0 != balance.value) || - (0 != balance.fraction) ) ) + ( (0 != nbalance.value) || + (0 != nbalance.fraction) ) ) { GNUNET_assert (GNUNET_OK == TALER_amount_add (&total_balance_reserve_not_closed, &total_balance_reserve_not_closed, - &balance)); + &nbalance)); report (report_reserve_not_closed_inconsistencies, json_pack ("{s:o, s:o, s:s}", "reserve_pub", GNUNET_JSON_from_data_auto (&rs->reserve_pub), "balance", - TALER_JSON_from_amount (&balance), + TALER_JSON_from_amount (&nbalance), "expiration_time", GNUNET_STRINGS_absolute_time_to_string ( rs->a_expiration_date))); @@ -1548,7 +1549,7 @@ verify_reserve_balance (void *cls, GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Final balance of reserve `%s' is %s, dropping it\n", TALER_B2S (&rs->reserve_pub), - TALER_amount2s (&balance)); + TALER_amount2s (&nbalance)); qs = adb->del_reserve_info (adb->cls, asession, &rs->reserve_pub, @@ -1566,7 +1567,7 @@ verify_reserve_balance (void *cls, GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Final balance of reserve `%s' is %s, no need to remember it\n", TALER_B2S (&rs->reserve_pub), - TALER_amount2s (&balance)); + TALER_amount2s (&nbalance)); } ret = GNUNET_OK; goto cleanup; @@ -1575,14 +1576,14 @@ verify_reserve_balance (void *cls, GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Remembering final balance of reserve `%s' as %s\n", TALER_B2S (&rs->reserve_pub), - TALER_amount2s (&balance)); + TALER_amount2s (&nbalance)); if (rs->had_ri) qs = adb->update_reserve_info (adb->cls, asession, &rs->reserve_pub, &master_pub, - &balance, + &nbalance, &rs->a_withdraw_fee_balance, rs->a_expiration_date); else @@ -1590,7 +1591,7 @@ verify_reserve_balance (void *cls, asession, &rs->reserve_pub, &master_pub, - &balance, + &nbalance, &rs->a_withdraw_fee_balance, rs->a_expiration_date); if (0 >= qs) @@ -2774,10 +2775,8 @@ check_wire_out_cb report (report_wire_out_inconsistencies, json_pack ("{s:O, s:I, s:o, s:o}", - "destination_account", - wire, - "rowid", - (json_int_t) rowid, + "destination_account", wire, + "rowid", (json_int_t) rowid, "expected", TALER_JSON_from_amount (&final_amount), "claimed", diff --git a/src/auditor/taler-wire-auditor.c b/src/auditor/taler-wire-auditor.c index a94cd5f68..8eec0dcf7 100644 --- a/src/auditor/taler-wire-auditor.c +++ b/src/auditor/taler-wire-auditor.c @@ -1175,7 +1175,7 @@ conclude_credit_history () * as claimed by the exchange DB. * * @param cls a `struct WireAccount` we are processing - * @param rowid unique serial ID for the refresh session in our DB + * @param rowid unique serial ID for the entry in our DB * @param reserve_pub public key of the reserve (also the WTID) * @param credit amount that was received * @param sender_url payto://-URL of the sender's bank account @@ -1198,7 +1198,8 @@ reserve_in_cb (void *cls, struct ReserveInInfo *rii; GNUNET_log (GNUNET_ERROR_TYPE_INFO, - "Analyzing exchange wire IN at %s of %s with reserve_pub %s\n", + "Analyzing exchange wire IN (%llu) at %s of %s with reserve_pub %s\n", + (unsigned long long) rowid, GNUNET_STRINGS_absolute_time_to_string (execution_date), TALER_amount2s (credit), TALER_B2S (reserve_pub)); @@ -1256,9 +1257,8 @@ complain_in_not_found (void *cls, struct WireAccount *wa = cls; struct ReserveInInfo *rii = value; - (void) wa; // FIXME: log which account is affected... report (report_reserve_in_inconsistencies, - json_pack ("{s:I, s:o, s:o, s:o, s:s, s:s}", + json_pack ("{s:I, s:o, s:o, s:o, s:s, s:s, s:s}", "row", (json_int_t) rii->rowid, "amount_expected", TALER_JSON_from_amount ( &rii->details.amount), @@ -1266,6 +1266,7 @@ complain_in_not_found (void *cls, "wtid", GNUNET_JSON_from_data_auto (&rii->details.wtid), "timestamp", GNUNET_STRINGS_absolute_time_to_string ( rii->details.execution_date), + "account", wa->section_name, "diagnostic", "incoming wire transfer claimed by exchange not found")); GNUNET_break (GNUNET_OK == @@ -1379,9 +1380,11 @@ history_credit_cb (void *cls, { GNUNET_break (0); report (report_row_inconsistencies, - json_pack ("{s:s, s:o, s:o, s:s}", + json_pack ("{s:s, s:I, s:o, s:o, s:s}", "table", "reserves_in", - "row", GNUNET_JSON_from_data (row_off, row_off_size), + "row", (json_int_t) rii->rowid, + "raw_bank_row", GNUNET_JSON_from_data (row_off, + row_off_size), "wire_offset_hash", GNUNET_JSON_from_data_auto (&key), "diagnostic", "wire reference size missmatch")); return GNUNET_OK; @@ -1390,8 +1393,10 @@ history_credit_cb (void *cls, &rii->details.wtid)) { report (report_reserve_in_inconsistencies, - json_pack ("{s:I, s:o, s:o, s:o, s:s, s:s}", - "row", GNUNET_JSON_from_data (row_off, row_off_size), + json_pack ("{s:I, s:o, s:o, s:o, s:o, s:s, s:s}", + "row", (json_int_t) rii->rowid, + "raw_bank_row", GNUNET_JSON_from_data (row_off, + row_off_size), "amount_exchange_expected", TALER_JSON_from_amount ( &rii->details.amount), "amount_wired", TALER_JSON_from_amount (&zero), @@ -1404,8 +1409,10 @@ history_credit_cb (void *cls, &total_bad_amount_in_minus, &rii->details.amount)); report (report_reserve_in_inconsistencies, - json_pack ("{s:I, s:o, s:o, s:o, s:s, s:s}", - "row", GNUNET_JSON_from_data (row_off, row_off_size), + json_pack ("{s:I, s:o, s:o, s:o, s:o, s:s, s:s}", + "row", (json_int_t) rii->rowid, + "raw_bank_row", GNUNET_JSON_from_data (row_off, + row_off_size), "amount_exchange_expected", TALER_JSON_from_amount ( &zero), "amount_wired", TALER_JSON_from_amount ( @@ -1425,8 +1432,10 @@ history_credit_cb (void *cls, &details->amount)) { report (report_reserve_in_inconsistencies, - json_pack ("{s:I, s:o, s:o, s:o, s:s, s:s}", - "row", GNUNET_JSON_from_data (row_off, row_off_size), + json_pack ("{s:I, s:o, s:o, s:o, s:o, s:s, s:s}", + "row", (json_int_t) rii->rowid, + "raw_bank_row", GNUNET_JSON_from_data (row_off, + row_off_size), "amount_exchange_expected", TALER_JSON_from_amount ( &rii->details.amount), "amount_wired", TALER_JSON_from_amount ( @@ -1470,9 +1479,11 @@ history_credit_cb (void *cls, rii->details.account_url)) { report (report_missattribution_in_inconsistencies, - json_pack ("{s:s, s:o, s:o}", + json_pack ("{s:s, s:I, s:o, s:o}", "amount", TALER_JSON_from_amount (&rii->details.amount), - "row", GNUNET_JSON_from_data (row_off, row_off_size), + "row", (json_int_t) rii->rowid, + "raw_bank_row", GNUNET_JSON_from_data (row_off, + row_off_size), "wtid", GNUNET_JSON_from_data_auto ( &rii->details.wtid))); GNUNET_break (GNUNET_OK == @@ -1484,9 +1495,11 @@ history_credit_cb (void *cls, rii->details.execution_date.abs_value_us) { report (report_row_minor_inconsistencies, - json_pack ("{s:s, s:o, s:s}", + json_pack ("{s:s, s:I, s:o, s:s}", "table", "reserves_in", - "row", GNUNET_JSON_from_data (row_off, row_off_size), + "row", (json_int_t) rii->rowid, + "raw_bank_row", GNUNET_JSON_from_data (row_off, + row_off_size), "diagnostic", "execution date missmatch")); } cleanup: diff --git a/src/auditor/test-auditor.sh b/src/auditor/test-auditor.sh index 260124fab..a5c20577b 100755 --- a/src/auditor/test-auditor.sh +++ b/src/auditor/test-auditor.sh @@ -7,56 +7,145 @@ # Requires 'jq' tool and Postgres superuser rights! set -eu +function exit_skip() { + echo $1 + exit 77 +} + +function exit_fail() { + echo $1 + kill `jobs -p` + exit 1 +} + +function run_audit () { + # Launch bank + echo "Launching bank" + taler-bank-manage -c test-auditor.conf serve-http 2>bank.err >bank.log & + while true + do + echo -n "." + wget http://localhost:8082/ -o /dev/null -O /dev/null >/dev/null && break + sleep 1 + done + echo "OK" + + # Run the auditor! + echo "Running audit(s)" + taler-auditor -r -c test-auditor.conf -m $MASTER_PUB > test-audit.json || exit_fail "auditor failed" + + taler-wire-auditor -r -c test-auditor.conf -m $MASTER_PUB > test-wire-audit.json || exit_fail "wire auditor failed" + + echo "Shutting down services" + kill `jobs -p` + + echo "TeXing" + ../../contrib/render.py test-audit.json test-wire-audit.json < ../../contrib/auditor-report.tex.j2 > test-report.tex || exit_fail Renderer failed + + pdflatex test-report.tex >/dev/null || exit_fail pdflatex failed + pdflatex test-report.tex >/dev/null +} + + # test required commands exist echo "Testing for jq" -jq -h > /dev/null || exit 77 +jq -h > /dev/null || exit_skip "jq required" echo "Testing for taler-bank-manage" -taler-bank-manage -h >/dev/null || exit 77 +taler-bank-manage -h >/dev/null /dev/null || exit 77 +which pdflatex > /dev/null /dev/null || true -createdb -T template0 $DB || exit 77 +createdb -T template0 $DB || exit_skip "could not create database" # Import pre-generated database, -q(ietly) using single (-1) transaction psql $DB -q -1 -f ../benchmark/auditor-basedb.sql > /dev/null MASTER_PUB=`cat ../benchmark/auditor-basedb.mpub` -# Launch bank -echo "Launching bank" -taler-bank-manage -c test-auditor.conf serve-http 2>/dev/null >/dev/null & - - -# Run the auditor! -echo "Running audit(s)" -taler-auditor -c test-auditor.conf -m $MASTER_PUB > test-audit.json - -# TODO: -# - need to configure exchange's bank accounts in test-auditor.conf, -# otherwise the auditor cannot find them! -taler-wire-auditor -c test-auditor.conf -m $MASTER_PUB > test-wire-audit.json - -echo "Shutting down services" -kill `jobs -p` - - -echo "TeXing" -../../contrib/render.py test-audit.json test-wire-audit.json < ../../contrib/auditor-report.tex.j2 > test-report.tex - -pdflatex test-report.tex >/dev/null -pdflatex test-report.tex >/dev/null +echo "===========1: normal run===========" +run_audit echo "Checking output" fail=0 # if an emergency was detected, that is a bug and we should fail echo -n "Test for emergencies... " -jq -e .emergencies[0] < test-audit.json > /dev/null && (echo Failed; fail=1) || echo OK - +jq -e .emergencies[0] < test-audit.json > /dev/null && exit_fail "Unexpected emergency detected in ordinary run" || echo OK + +echo -n "Test for wire inconsistencies... " +jq -e .wire_out_amount_inconsistencies[0] < test-wire-audit.json > /dev/null && exit_fail "Unexpected wire out inconsistency detected in ordinary run" +jq -e .reserve_in_amount_inconsistencies[0] < test-wire-audit.json > /dev/null && exit_fail "Unexpected reserve in inconsistency detected in ordinary run" +jq -e .missattribution_inconsistencies[0] < test-wire-audit.json > /dev/null && exit_fail "Unexpected missattribution inconsistency detected in ordinary run" +jq -e .row_inconsistencies[0] < test-wire-audit.json > /dev/null && exit_fail "Unexpected row inconsistency detected in ordinary run" +jq -e .row_minor_inconsistencies[0] < test-wire-audit.json > /dev/null && exit_fail "Unexpected minor row inconsistency detected in ordinary run" +jq -e .lag_details[0] < test-wire-audit.json > /dev/null && exit_fail "Unexpected lag detected in ordinary run" +jq -e .wire_format_inconsistencies[0] < test-wire-audit.json > /dev/null && exit_fail "Unexpected wire format inconsistencies detected in ordinary run" + +echo OK + +echo -n "Test for wire amounts... " +WIRED=`jq -r .total_wire_in_delta_plus < test-wire-audit.json` +if test $WIRED != "TESTKUDOS:0" +then + exit_fail "Expected total wire delta plus wrong, got $WIRED" +fi +WIRED=`jq -r .total_wire_in_delta_minus < test-wire-audit.json` +if test $WIRED != "TESTKUDOS:0" +then + exit_fail "Expected total wire delta minus wrong, got $WIRED" +fi +WIRED=`jq -r .total_wire_out_delta_plus < test-wire-audit.json` +if test $WIRED != "TESTKUDOS:0" +then + exit_fail "Expected total wire delta plus wrong, got $WIRED" +fi +WIRED=`jq -r .total_wire_out_delta_minus < test-wire-audit.json` +if test $WIRED != "TESTKUDOS:0" +then + exit_fail "Expected total wire delta minus wrong, got $WIRED" +fi +WIRED=`jq -r .total_missattribution_in < test-wire-audit.json` +if test $WIRED != "TESTKUDOS:0" +then + exit_fail "Expected total missattribution in wrong, got $WIRED" +fi +echo "OK" + + +echo "===========2: reserves_in inconsitency===========" # TODO: Add more checks to ensure test-audit.json matches expectations echo "UPDATE reserves_in SET credit_val=5 WHERE reserve_in_serial_id=1" | psql $DB +run_audit + +echo -n "Test for inconsistency detection... " +ROW=`jq .reserve_in_amount_inconsistencies[0].row < test-wire-audit.json` +if test $ROW != 1 +then + exit_fail "Row wrong" +fi +WIRED=`jq -r .reserve_in_amount_inconsistencies[0].amount_wired < test-wire-audit.json` +if test $WIRED != "TESTKUDOS:10" +then + exit_fail "Amount wrong" +fi +EXPECTED=`jq -r .reserve_in_amount_inconsistencies[0].amount_exchange_expected < test-wire-audit.json` +if test $EXPECTED != "TESTKUDOS:5" +then + exit_fail "Expected amount wrong" +fi +DELTA=`jq -r .total_wire_in_delta_plus < test-wire-audit.json` +if test $DELTA != "TESTKUDOS:5" +then + exit_fail "Expected total wire delta plus wrong" +fi +echo OK + +# Undo database modification +echo "UPDATE reserves_in SET credit_val=10 WHERE reserve_in_serial_id=1" | psql $DB + +# TODO: insert more tests! echo "Cleanup" dropdb $DB diff --git a/src/auditordb/plugin_auditordb_postgres.c b/src/auditordb/plugin_auditordb_postgres.c index 555c3058b..daa1c1418 100644 --- a/src/auditordb/plugin_auditordb_postgres.c +++ b/src/auditordb/plugin_auditordb_postgres.c @@ -2228,9 +2228,13 @@ postgres_insert_wire_auditor_account_progress (void *cls, GNUNET_PQ_query_param_uint64 (&pp->last_reserve_in_serial_id), GNUNET_PQ_query_param_uint64 (&pp->last_wire_out_serial_id), GNUNET_PQ_query_param_fixed_size (in_wire_off, - wire_off_size), + NULL == in_wire_off + ? 0 + : wire_off_size), GNUNET_PQ_query_param_fixed_size (out_wire_off, - wire_off_size), + NULL == out_wire_off + ? 0 + : wire_off_size), GNUNET_PQ_query_param_end }; @@ -2269,9 +2273,13 @@ postgres_update_wire_auditor_account_progress (void *cls, GNUNET_PQ_query_param_uint64 (&pp->last_reserve_in_serial_id), GNUNET_PQ_query_param_uint64 (&pp->last_wire_out_serial_id), GNUNET_PQ_query_param_fixed_size (in_wire_off, - wire_off_size), + NULL == in_wire_off + ? 0 + : wire_off_size), GNUNET_PQ_query_param_fixed_size (out_wire_off, - wire_off_size), + NULL == out_wire_off + ? 0 + : wire_off_size), GNUNET_PQ_query_param_auto_from_type (master_pub), GNUNET_PQ_query_param_string (account_name), GNUNET_PQ_query_param_end @@ -2340,7 +2348,11 @@ postgres_get_wire_auditor_account_progress (void *cls, *wire_off_size = 0; xsize = 0; } - GNUNET_assert (xsize == *wire_off_size); + if ( (0 != xsize) && + (0 != *wire_off_size) ) + { + GNUNET_assert (xsize == *wire_off_size); + } return qs; } -- cgit v1.2.3