From 10c56bcea05df9ac5a7036850039900fbe435e00 Mon Sep 17 00:00:00 2001 From: Christian Grothoff Date: Fri, 20 Mar 2020 02:36:50 +0100 Subject: improving benchmarking logic, including more timings --- src/benchmark/benchmark.conf | 2 +- src/benchmark/taler-exchange-benchmark.c | 168 +++++++++++------- src/include/taler_error_codes.h | 49 ++++++ src/include/taler_testing_lib.h | 43 +++++ src/json/json.c | 1 - src/lib/auditor_api_exchanges.c | 18 +- src/lib/exchange_api_deposit.c | 4 +- src/lib/exchange_api_link.c | 6 +- src/lib/exchange_api_melt.c | 8 +- src/lib/exchange_api_recoup.c | 15 +- src/lib/exchange_api_refreshes_reveal.c | 14 +- src/lib/exchange_api_reserves_get.c | 12 +- src/lib/exchange_api_transfers_get.c | 10 +- src/lib/exchange_api_wire.c | 16 +- src/lib/exchange_api_withdraw.c | 25 ++- src/testing/Makefile.am | 1 + .../testing_api_cmd_auditor_deposit_confirmation.c | 9 +- src/testing/testing_api_cmd_auditor_exchanges.c | 9 +- .../testing_api_cmd_bank_admin_add_incoming.c | 9 +- src/testing/testing_api_cmd_batch.c | 5 +- src/testing/testing_api_cmd_deposit.c | 10 +- src/testing/testing_api_cmd_refresh.c | 67 +++++++- src/testing/testing_api_cmd_stat.c | 190 +++++++++++++++++++++ src/testing/testing_api_cmd_withdraw.c | 23 +++ src/testing/testing_api_loop.c | 7 +- 25 files changed, 622 insertions(+), 99 deletions(-) create mode 100644 src/testing/testing_api_cmd_stat.c (limited to 'src') diff --git a/src/benchmark/benchmark.conf b/src/benchmark/benchmark.conf index a7be9f0d3..fba3e0aa6 100644 --- a/src/benchmark/benchmark.conf +++ b/src/benchmark/benchmark.conf @@ -30,7 +30,7 @@ base_url = "http://localhost:8081/" lookahead_sign = 12 h [auditor] -BASE_URL = "http://localhost:8085/" +BASE_URL = "http://localhost:8083/" [exchangedb-postgres] config = "postgres:///talercheck" diff --git a/src/benchmark/taler-exchange-benchmark.c b/src/benchmark/taler-exchange-benchmark.c index 22b71948e..95c3ae239 100644 --- a/src/benchmark/taler-exchange-benchmark.c +++ b/src/benchmark/taler-exchange-benchmark.c @@ -211,6 +211,19 @@ static unsigned int label_off; */ static int linger; +/** + * Performance counters. + */ +static struct TALER_TESTING_Timer timings[] = { + { .prefix = "createreserve" }, + { .prefix = "withdraw" }, + { .prefix = "deposit" }, + { .prefix = "melt" }, + { .prefix = "reveal" }, + { .prefix = "link" }, + { .prefix = NULL } +}; + /** * Add label to the #labels table and return it. @@ -304,6 +317,7 @@ run (void *cls, (void) cls; all_commands = GNUNET_new_array (howmany_reserves * (1 /* Withdraw block */ + howmany_coins) /* All units */ + + 1 /* stat CMD */ + 1 /* End CMD */, struct TALER_TESTING_Command); GNUNET_asprintf (&amount_5, "%s:5", currency); @@ -328,7 +342,7 @@ run (void *cls, char *create_reserve_label; GNUNET_asprintf (&create_reserve_label, - "create-reserve-%u", + "createreserve-%u", j); { struct TALER_TESTING_Command make_reserve[] = { @@ -351,24 +365,26 @@ run (void *cls, char *order_enc; struct TALER_TESTING_Command unit[UNITY_SIZE]; char *unit_label; + const char *wl; GNUNET_asprintf (&withdraw_label, "withdraw-%u-%u", i, j); + wl = add_label (withdraw_label); GNUNET_asprintf (&order_enc, "{\"nonce\": %llu}", i + (howmany_coins * j)); unit[0] = TALER_TESTING_cmd_withdraw_with_retry - (TALER_TESTING_cmd_withdraw_amount (add_label (withdraw_label), + (TALER_TESTING_cmd_withdraw_amount (wl, create_reserve_label, amount_5, MHD_HTTP_OK)); unit[1] = TALER_TESTING_cmd_deposit_with_retry (TALER_TESTING_cmd_deposit ("deposit", - add_label (withdraw_label), + wl, 0, /* Index of the one withdrawn coin in the traits. */ user_payto_uri, add_label (order_enc), @@ -379,34 +395,35 @@ run (void *cls, { char *melt_label; char *reveal_label; + const char *ml; + const char *rl; GNUNET_asprintf (&melt_label, - "refresh-melt-%u-%u", + "melt-%u-%u", i, j); + ml = add_label (melt_label); GNUNET_asprintf (&reveal_label, - "refresh-reveal-%u-%u", + "reveal-%u-%u", i, j); + rl = add_label (reveal_label); unit[2] = TALER_TESTING_cmd_melt_with_retry - (TALER_TESTING_cmd_melt - (add_label (melt_label), - withdraw_label, - MHD_HTTP_OK, - NULL)); + (TALER_TESTING_cmd_melt (ml, + wl, + MHD_HTTP_OK, + NULL)); unit[3] = TALER_TESTING_cmd_refresh_reveal_with_retry - (TALER_TESTING_cmd_refresh_reveal - (add_label (reveal_label), - melt_label, - MHD_HTTP_OK)); + (TALER_TESTING_cmd_refresh_reveal (rl, + ml, + MHD_HTTP_OK)); unit[4] = TALER_TESTING_cmd_refresh_link_with_retry - (TALER_TESTING_cmd_refresh_link - ("refresh-link", - reveal_label, - MHD_HTTP_OK)); + (TALER_TESTING_cmd_refresh_link ("link", + rl, + MHD_HTTP_OK)); unit[5] = TALER_TESTING_cmd_end (); } else @@ -422,6 +439,8 @@ run (void *cls, } } all_commands[howmany_reserves * (1 + howmany_coins)] + = TALER_TESTING_cmd_stat (timings); + all_commands[howmany_reserves * (1 + howmany_coins) + 1] = TALER_TESTING_cmd_end (); TALER_TESTING_run2 (is, all_commands, @@ -434,6 +453,24 @@ run (void *cls, } +/** + * Print performance statistics for this process. + */ +static void +print_stats (void) +{ + for (unsigned int i = 0; NULL != timings[i].prefix; i++) + fprintf (stderr, + "%s-%d took %s in total for %u executions\n", + timings[i].prefix, + (int) getpid (), + GNUNET_STRINGS_relative_time_to_string ( + timings[i].total_duration, + GNUNET_YES), + timings[i].num_commands); +} + + /** * Stop the fakebank. * @@ -712,53 +749,68 @@ parallel_benchmark (TALER_TESTING_Main main_cb, } if ( (MODE_CLIENT == mode) || (MODE_BOTH == mode) ) { - sleep (1); /* make sure fakebank process is ready before continuing */ + if (-1 != fakebank) + sleep (1); /* make sure fakebank process is ready before continuing */ start_time = GNUNET_TIME_absolute_get (); result = GNUNET_OK; - for (unsigned int i = 0; ijob = NULL; switch (response_code) { case 0: + ec = TALER_EC_INVALID_RESPONSE; break; case MHD_HTTP_OK: ja = json_object_get (json, @@ -102,6 +104,7 @@ handle_exchanges_finished (void *cls, (! json_is_array (ja)) ) { GNUNET_break (0); + ec = TALER_EC_AUDITOR_EXCHANGES_REPLY_MALFORMED; response_code = 0; break; } @@ -110,6 +113,7 @@ handle_exchanges_finished (void *cls, if (ja_len > MAX_EXCHANGES) { GNUNET_break (0); + ec = TALER_EC_AUDITOR_EXCHANGES_REPLY_MALFORMED; response_code = 0; break; } @@ -134,6 +138,7 @@ handle_exchanges_finished (void *cls, { GNUNET_break_op (0); ok = GNUNET_NO; + ec = TALER_EC_AUDITOR_EXCHANGES_REPLY_MALFORMED; break; } } @@ -145,26 +150,31 @@ handle_exchanges_finished (void *cls, ja_len, ei, json); - leh->cb = NULL; + TALER_AUDITOR_list_exchanges_cancel (leh); + return; } - break; case MHD_HTTP_BAD_REQUEST: /* This should never happen, either us or the auditor is buggy (or API version conflict); just pass JSON reply to the application */ + ec = TALER_JSON_get_error_code (json); break; case MHD_HTTP_NOT_FOUND: /* Nothing really to verify, this should never happen, we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (json); break; case MHD_HTTP_INTERNAL_SERVER_ERROR: /* Server had an internal issue; we should retry, but this API leaves this to the application */ + ec = TALER_JSON_get_error_code (json); break; default: /* unexpected response code */ + ec = TALER_JSON_get_error_code (json); GNUNET_log (GNUNET_ERROR_TYPE_ERROR, - "Unexpected response code %u\n", - (unsigned int) response_code); + "Unexpected response code %u/%d\n", + (unsigned int) response_code, + (int) ec); GNUNET_break (0); response_code = 0; break; diff --git a/src/lib/exchange_api_deposit.c b/src/lib/exchange_api_deposit.c index 3fb36d240..8c00effcf 100644 --- a/src/lib/exchange_api_deposit.c +++ b/src/lib/exchange_api_deposit.c @@ -38,10 +38,10 @@ * 1:#AUDITOR_CHANCE is the probability that we report deposits * to the auditor. * - * 2==50% of going to auditor. This is way too high, but set + * 20==5% of going to auditor. This is possibly still too high, but set * deliberately this high for testing */ -#define AUDITOR_CHANCE 2 +#define AUDITOR_CHANCE 20 /** * @brief A Deposit Handle diff --git a/src/lib/exchange_api_link.c b/src/lib/exchange_api_link.c index 756340494..5a2fc2a13 100644 --- a/src/lib/exchange_api_link.c +++ b/src/lib/exchange_api_link.c @@ -365,8 +365,12 @@ handle_link_finished (void *cls, { GNUNET_break_op (0); response_code = 0; + ec = TALER_EC_REFRESH_LINK_REPLY_MALFORMED; + break; } - break; + GNUNET_assert (NULL == lh->link_cb); + TALER_EXCHANGE_link_cancel (lh); + return; case MHD_HTTP_BAD_REQUEST: ec = TALER_JSON_get_error_code (j); /* This should never happen, either us or the exchange is buggy diff --git a/src/lib/exchange_api_melt.c b/src/lib/exchange_api_melt.c index 621e9e1df..d6acf92c7 100644 --- a/src/lib/exchange_api_melt.c +++ b/src/lib/exchange_api_melt.c @@ -304,9 +304,9 @@ handle_melt_finished (void *cls, } break; case MHD_HTTP_BAD_REQUEST: - ec = TALER_JSON_get_error_code (j); /* This should never happen, either us or the exchange is buggy (or API version conflict); just pass JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_CONFLICT: /* Double spending; check signatures on transaction history */ @@ -322,20 +322,20 @@ handle_melt_finished (void *cls, ec = TALER_EC_NONE; break; case MHD_HTTP_FORBIDDEN: - ec = TALER_JSON_get_error_code (j); /* Nothing really to verify, exchange says one of the signatures is invalid; assuming we checked them, this should never happen, we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_NOT_FOUND: - ec = TALER_JSON_get_error_code (j); /* Nothing really to verify, this should never happen, we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_INTERNAL_SERVER_ERROR: - ec = TALER_JSON_get_error_code (j); /* Server had an internal issue; we should retry, but this API leaves this to the application */ + ec = TALER_JSON_get_error_code (j); break; default: /* unexpected response code */ diff --git a/src/lib/exchange_api_recoup.c b/src/lib/exchange_api_recoup.c index 5a2759356..54bcab095 100644 --- a/src/lib/exchange_api_recoup.c +++ b/src/lib/exchange_api_recoup.c @@ -206,18 +206,22 @@ handle_recoup_finished (void *cls, { struct TALER_EXCHANGE_RecoupHandle *ph = cls; const json_t *j = response; + enum TALER_ErrorCode ec; ph->job = NULL; switch (response_code) { case 0: + ec = TALER_EC_INVALID_RESPONSE; break; case MHD_HTTP_OK: + ec = TALER_EC_NONE; if (GNUNET_OK != verify_recoup_signature_ok (ph, j)) { GNUNET_break_op (0); + ec = TALER_EC_RECOUP_REPLY_MALFORMED; response_code = 0; break; } @@ -226,6 +230,7 @@ handle_recoup_finished (void *cls, case MHD_HTTP_BAD_REQUEST: /* This should never happen, either us or the exchange is buggy (or API version conflict); just pass JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_CONFLICT: { @@ -247,9 +252,10 @@ handle_recoup_finished (void *cls, GNUNET_break_op (0); response_code = 0; } + ec = TALER_JSON_get_error_code (j); ph->cb (ph->cb_cls, response_code, - TALER_JSON_get_error_code (j), + ec, &total, GNUNET_TIME_UNIT_FOREVER_ABS, NULL, @@ -262,21 +268,26 @@ handle_recoup_finished (void *cls, /* Nothing really to verify, exchange says one of the signatures is invalid; as we checked them, this should never happen, we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_NOT_FOUND: /* Nothing really to verify, this should never happen, we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_GONE: /* Kind of normal: the money was already sent to the merchant (it was too late for the refund). */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_INTERNAL_SERVER_ERROR: /* Server had an internal issue; we should retry, but this API leaves this to the application */ + ec = TALER_JSON_get_error_code (j); break; default: /* unexpected response code */ + ec = TALER_JSON_get_error_code (j); GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Unexpected response code %u\n", (unsigned int) response_code); @@ -286,7 +297,7 @@ handle_recoup_finished (void *cls, } ph->cb (ph->cb_cls, response_code, - TALER_JSON_get_error_code (j), + ec, NULL, GNUNET_TIME_UNIT_FOREVER_ABS, NULL, diff --git a/src/lib/exchange_api_refreshes_reveal.c b/src/lib/exchange_api_refreshes_reveal.c index 8ac7d4a9d..0fdbf7c69 100644 --- a/src/lib/exchange_api_refreshes_reveal.c +++ b/src/lib/exchange_api_refreshes_reveal.c @@ -202,11 +202,13 @@ handle_refresh_reveal_finished (void *cls, { struct TALER_EXCHANGE_RefreshesRevealHandle *rrh = cls; const json_t *j = response; + enum TALER_ErrorCode ec; rrh->job = NULL; switch (response_code) { case 0: + ec = TALER_EC_INVALID_RESPONSE; break; case MHD_HTTP_OK: { @@ -220,12 +222,14 @@ handle_refresh_reveal_finished (void *cls, if (GNUNET_OK != ret) { response_code = 0; + ec = TALER_EC_REFRESH_REVEAL_REPLY_MALFORMED; } else { + ec = TALER_EC_NONE; rrh->reveal_cb (rrh->reveal_cb_cls, MHD_HTTP_OK, - TALER_EC_NONE, + ec, rrh->md->num_fresh_coins, rrh->md->fresh_coins[rrh->noreveal_index], sigs, @@ -235,20 +239,23 @@ handle_refresh_reveal_finished (void *cls, for (unsigned int i = 0; imd->num_fresh_coins; i++) if (NULL != sigs[i].rsa_signature) GNUNET_CRYPTO_rsa_signature_free (sigs[i].rsa_signature); + return; } - break; case MHD_HTTP_BAD_REQUEST: /* This should never happen, either us or the exchange is buggy (or API version conflict); just pass JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_CONFLICT: /* Nothing really to verify, exchange says our reveal is inconsitent with our commitment, so either side is buggy; we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_INTERNAL_SERVER_ERROR: /* Server had an internal issue; we should retry, but this API leaves this to the application */ + ec = TALER_JSON_get_error_code (j); break; default: /* unexpected response code */ @@ -257,12 +264,13 @@ handle_refresh_reveal_finished (void *cls, (unsigned int) response_code); GNUNET_break (0); response_code = 0; + ec = TALER_JSON_get_error_code (j); break; } if (NULL != rrh->reveal_cb) rrh->reveal_cb (rrh->reveal_cb_cls, response_code, - TALER_JSON_get_error_code (j), + ec, 0, NULL, NULL, diff --git a/src/lib/exchange_api_reserves_get.c b/src/lib/exchange_api_reserves_get.c index 39932d650..e44eefad6 100644 --- a/src/lib/exchange_api_reserves_get.c +++ b/src/lib/exchange_api_reserves_get.c @@ -171,32 +171,42 @@ handle_reserves_get_finished (void *cls, { struct TALER_EXCHANGE_ReservesGetHandle *rgh = cls; const json_t *j = response; + enum TALER_ErrorCode ec; rgh->job = NULL; switch (response_code) { case 0: + ec = TALER_EC_INVALID_RESPONSE; break; case MHD_HTTP_OK: + ec = TALER_EC_NONE; if (GNUNET_OK != handle_reserves_get_ok (rgh, j)) + { response_code = 0; + ec = TALER_EC_RESERVE_STATUS_REPLY_MALFORMED; + } break; case MHD_HTTP_BAD_REQUEST: /* This should never happen, either us or the exchange is buggy (or API version conflict); just pass JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_NOT_FOUND: /* Nothing really to verify, this should never happen, we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_INTERNAL_SERVER_ERROR: /* Server had an internal issue; we should retry, but this API leaves this to the application */ + ec = TALER_JSON_get_error_code (j); break; default: /* unexpected response code */ + ec = TALER_JSON_get_error_code (j); GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Unexpected response code %u\n", (unsigned int) response_code); @@ -208,7 +218,7 @@ handle_reserves_get_finished (void *cls, { rgh->cb (rgh->cb_cls, response_code, - TALER_JSON_get_error_code (j), + ec, j, NULL, 0, NULL); diff --git a/src/lib/exchange_api_transfers_get.c b/src/lib/exchange_api_transfers_get.c index 6d61e1d04..617c897d3 100644 --- a/src/lib/exchange_api_transfers_get.c +++ b/src/lib/exchange_api_transfers_get.c @@ -261,11 +261,13 @@ handle_transfers_get_finished (void *cls, { struct TALER_EXCHANGE_TransfersGetHandle *wdh = cls; const json_t *j = response; + enum TALER_ErrorCode ec; wdh->job = NULL; switch (response_code) { case 0: + ec = TALER_EC_INVALID_RESPONSE; break; case MHD_HTTP_OK: if (GNUNET_OK == @@ -273,27 +275,33 @@ handle_transfers_get_finished (void *cls, j)) return; GNUNET_break_op (0); + ec = TALER_EC_TRACK_TRANSFER_REPLY_MALFORMED; response_code = 0; break; case MHD_HTTP_BAD_REQUEST: /* This should never happen, either us or the exchange is buggy (or API version conflict); just pass JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_FORBIDDEN: /* Nothing really to verify, exchange says one of the signatures is invalid; as we checked them, this should never happen, we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_NOT_FOUND: /* Exchange does not know about transaction; we should pass the reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_INTERNAL_SERVER_ERROR: /* Server had an internal issue; we should retry, but this API leaves this to the application */ + ec = TALER_JSON_get_error_code (j); break; default: /* unexpected response code */ + ec = TALER_JSON_get_error_code (j); GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Unexpected response code %u\n", (unsigned int) response_code); @@ -303,7 +311,7 @@ handle_transfers_get_finished (void *cls, } wdh->cb (wdh->cb_cls, response_code, - TALER_JSON_get_error_code (j), + ec, NULL, j, NULL, diff --git a/src/lib/exchange_api_wire.c b/src/lib/exchange_api_wire.c index 1ac44c70e..ccab4562d 100644 --- a/src/lib/exchange_api_wire.c +++ b/src/lib/exchange_api_wire.c @@ -213,10 +213,10 @@ handle_wire_finished (void *cls, TALER_LOG_DEBUG ("Checking raw /wire response\n"); wh->job = NULL; - ec = TALER_EC_NONE; switch (response_code) { case 0: + ec = TALER_EC_INVALID_RESPONSE; break; case MHD_HTTP_OK: { @@ -261,6 +261,7 @@ handle_wire_finished (void *cls, break; } + ec = TALER_EC_NONE; key_state = TALER_EXCHANGE_get_keys (wh->exchange); /* parse accounts */ { @@ -325,7 +326,7 @@ handle_wire_finished (void *cls, { wh->cb (wh->cb_cls, response_code, - TALER_EC_NONE, + ec, num_accounts, was); wh->cb = NULL; @@ -338,20 +339,25 @@ handle_wire_finished (void *cls, case MHD_HTTP_BAD_REQUEST: /* This should never happen, either us or the exchange is buggy (or API version conflict); just pass JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_NOT_FOUND: /* Nothing really to verify, this should never happen, we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_INTERNAL_SERVER_ERROR: /* Server had an internal issue; we should retry, but this API leaves this to the application */ + ec = TALER_JSON_get_error_code (j); break; default: /* unexpected response code */ + ec = TALER_JSON_get_error_code (j); GNUNET_log (GNUNET_ERROR_TYPE_ERROR, - "Unexpected response code %u\n", - (unsigned int) response_code); + "Unexpected response code %u/%d\n", + (unsigned int) response_code, + (int) ec); GNUNET_break (0); response_code = 0; break; @@ -359,7 +365,7 @@ handle_wire_finished (void *cls, if (NULL != wh->cb) wh->cb (wh->cb_cls, response_code, - (0 == response_code) ? ec : TALER_JSON_get_error_code (j), + ec, 0, NULL); TALER_EXCHANGE_wire_cancel (wh); diff --git a/src/lib/exchange_api_withdraw.c b/src/lib/exchange_api_withdraw.c index d909693c1..a9fe477eb 100644 --- a/src/lib/exchange_api_withdraw.c +++ b/src/lib/exchange_api_withdraw.c @@ -277,11 +277,13 @@ handle_reserve_withdraw_finished (void *cls, { struct TALER_EXCHANGE_WithdrawHandle *wh = cls; const json_t *j = response; + enum TALER_ErrorCode ec; wh->job = NULL; switch (response_code) { case 0: + ec = TALER_EC_INVALID_RESPONSE; break; case MHD_HTTP_OK: if (GNUNET_OK != @@ -290,11 +292,16 @@ handle_reserve_withdraw_finished (void *cls, { GNUNET_break_op (0); response_code = 0; + ec = TALER_EC_WITHDRAW_REPLY_MALFORMED; + break; } - break; + GNUNET_assert (NULL == wh->cb); + TALER_EXCHANGE_withdraw_cancel (wh); + return; case MHD_HTTP_BAD_REQUEST: /* This should never happen, either us or the exchange is buggy (or API version conflict); just pass JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_CONFLICT: /* The exchange says that the reserve has insufficient funds; @@ -305,6 +312,11 @@ handle_reserve_withdraw_finished (void *cls, { GNUNET_break_op (0); response_code = 0; + ec = TALER_EC_WITHDRAW_REPLY_MALFORMED; + } + else + { + ec = TALER_JSON_get_error_code (j); } break; case MHD_HTTP_FORBIDDEN: @@ -312,22 +324,27 @@ handle_reserve_withdraw_finished (void *cls, /* Nothing really to verify, exchange says one of the signatures is invalid; as we checked them, this should never happen, we should pass the JSON reply to the application */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_NOT_FOUND: /* Nothing really to verify, the exchange basically just says that it doesn't know this reserve. Can happen if we query before the wire transfer went through. We should simply pass the JSON reply to the application. */ + ec = TALER_JSON_get_error_code (j); break; case MHD_HTTP_INTERNAL_SERVER_ERROR: /* Server had an internal issue; we should retry, but this API leaves this to the application */ + ec = TALER_JSON_get_error_code (j); break; default: /* unexpected response code */ + ec = TALER_JSON_get_error_code (j); GNUNET_log (GNUNET_ERROR_TYPE_ERROR, - "Unexpected response code %u\n", - (unsigned int) response_code); + "Unexpected response code %u/%d\n", + (unsigned int) response_code, + (int) ec); GNUNET_break (0); response_code = 0; break; @@ -336,7 +353,7 @@ handle_reserve_withdraw_finished (void *cls, { wh->cb (wh->cb_cls, response_code, - TALER_JSON_get_error_code (j), + ec, NULL, j); wh->cb = NULL; diff --git a/src/testing/Makefile.am b/src/testing/Makefile.am index faad3f731..5d3905d9d 100644 --- a/src/testing/Makefile.am +++ b/src/testing/Makefile.am @@ -62,6 +62,7 @@ libtalertesting_la_SOURCES = \ testing_api_cmd_serialize_keys.c \ testing_api_cmd_signal.c \ testing_api_cmd_sleep.c \ + testing_api_cmd_stat.c \ testing_api_cmd_status.c \ testing_api_cmd_track.c \ testing_api_cmd_wait.c \ diff --git a/src/testing/testing_api_cmd_auditor_deposit_confirmation.c b/src/testing/testing_api_cmd_auditor_deposit_confirmation.c index bcef59c59..9981bc593 100644 --- a/src/testing/testing_api_cmd_auditor_deposit_confirmation.c +++ b/src/testing/testing_api_cmd_auditor_deposit_confirmation.c @@ -29,6 +29,12 @@ #include "taler_signatures.h" #include "backoff.h" +/** + * How long do we wait AT MOST when retrying? + */ +#define MAX_BACKOFF GNUNET_TIME_relative_multiply ( \ + GNUNET_TIME_UNIT_MILLISECONDS, 100) + /** * How often do we retry before giving up? */ @@ -160,7 +166,8 @@ deposit_confirmation_cb (void *cls, if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec) dcs->backoff = GNUNET_TIME_UNIT_ZERO; else - dcs->backoff = EXCHANGE_LIB_BACKOFF (dcs->backoff); + dcs->backoff = GNUNET_TIME_randomized_backoff (dcs->backoff, + MAX_BACKOFF); dcs->retry_task = GNUNET_SCHEDULER_add_delayed (dcs->backoff, &do_retry, dcs); diff --git a/src/testing/testing_api_cmd_auditor_exchanges.c b/src/testing/testing_api_cmd_auditor_exchanges.c index b5a1cab0e..688d5830b 100644 --- a/src/testing/testing_api_cmd_auditor_exchanges.c +++ b/src/testing/testing_api_cmd_auditor_exchanges.c @@ -29,6 +29,12 @@ #include "taler_signatures.h" #include "backoff.h" +/** + * How long do we wait AT MOST when retrying? + */ +#define MAX_BACKOFF GNUNET_TIME_relative_multiply ( \ + GNUNET_TIME_UNIT_MILLISECONDS, 100) + /** * How often do we retry before giving up? @@ -153,7 +159,8 @@ exchanges_cb (void *cls, if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec) es->backoff = GNUNET_TIME_UNIT_ZERO; else - es->backoff = EXCHANGE_LIB_BACKOFF (es->backoff); + es->backoff = GNUNET_TIME_randomized_backoff (es->backoff, + MAX_BACKOFF); es->retry_task = GNUNET_SCHEDULER_add_delayed (es->backoff, &do_retry, es); diff --git a/src/testing/testing_api_cmd_bank_admin_add_incoming.c b/src/testing/testing_api_cmd_bank_admin_add_incoming.c index 6e707a2e4..ddd27babb 100644 --- a/src/testing/testing_api_cmd_bank_admin_add_incoming.c +++ b/src/testing/testing_api_cmd_bank_admin_add_incoming.c @@ -31,6 +31,12 @@ #include "taler_signatures.h" #include "taler_testing_lib.h" +/** + * How long do we wait AT MOST when retrying? + */ +#define MAX_BACKOFF GNUNET_TIME_relative_multiply ( \ + GNUNET_TIME_UNIT_MILLISECONDS, 100) + /** * How often do we retry before giving up? @@ -206,7 +212,8 @@ confirmation_cb (void *cls, if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec) fts->backoff = GNUNET_TIME_UNIT_ZERO; else - fts->backoff = EXCHANGE_LIB_BACKOFF (fts->backoff); + fts->backoff = GNUNET_TIME_randomized_backoff (fts->backoff, + MAX_BACKOFF); fts->retry_task = GNUNET_SCHEDULER_add_delayed (fts->backoff, &do_retry, diff --git a/src/testing/testing_api_cmd_batch.c b/src/testing/testing_api_cmd_batch.c index fe7c19db2..ebb4e6d9a 100644 --- a/src/testing/testing_api_cmd_batch.c +++ b/src/testing/testing_api_cmd_batch.c @@ -70,7 +70,7 @@ batch_run (void *cls, TALER_TESTING_interpreter_next (is); return; } - + bs->batch[bs->batch_ip].start_time = GNUNET_TIME_absolute_get (); bs->batch[bs->batch_ip].run (bs->batch[bs->batch_ip].cls, &bs->batch[bs->batch_ip], is); @@ -193,10 +193,11 @@ TALER_TESTING_cmd_batch_next (struct TALER_TESTING_Interpreter *is) if (NULL == bs->batch[bs->batch_ip].label) { + is->commands[is->ip].finish_time = GNUNET_TIME_absolute_get (); is->ip++; return; } - + bs->batch[bs->batch_ip].finish_time = GNUNET_TIME_absolute_get (); bs->batch_ip++; } diff --git a/src/testing/testing_api_cmd_deposit.c b/src/testing/testing_api_cmd_deposit.c index 6781568a1..6404a94a4 100644 --- a/src/testing/testing_api_cmd_deposit.c +++ b/src/testing/testing_api_cmd_deposit.c @@ -34,6 +34,12 @@ */ #define NUM_RETRIES 5 +/** + * How long do we wait AT MOST when retrying? + */ +#define MAX_BACKOFF GNUNET_TIME_relative_multiply ( \ + GNUNET_TIME_UNIT_MILLISECONDS, 100) + /** * State for a "deposit" CMD. @@ -205,7 +211,8 @@ deposit_cb (void *cls, if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec) ds->backoff = GNUNET_TIME_UNIT_ZERO; else - ds->backoff = EXCHANGE_LIB_BACKOFF (ds->backoff); + ds->backoff = GNUNET_TIME_randomized_backoff (ds->backoff, + MAX_BACKOFF); ds->retry_task = GNUNET_SCHEDULER_add_delayed (ds->backoff, &do_retry, @@ -355,7 +362,6 @@ deposit_run (void *cls, &coin_sig, &deposit_cb, ds); - if (NULL == ds->dh) { GNUNET_break (0); diff --git a/src/testing/testing_api_cmd_refresh.c b/src/testing/testing_api_cmd_refresh.c index 2f91df377..51c3890ba 100644 --- a/src/testing/testing_api_cmd_refresh.c +++ b/src/testing/testing_api_cmd_refresh.c @@ -28,11 +28,23 @@ #include "taler_signatures.h" #include "backoff.h" +/** + * How long do we wait AT MOST when retrying? + */ +#define MAX_BACKOFF GNUNET_TIME_relative_multiply ( \ + GNUNET_TIME_UNIT_MILLISECONDS, 100) + /** * How often do we retry before giving up? */ #define NUM_RETRIES 5 +/** + * How long do we wait AT MOST when retrying? + */ +#define MAX_BACKOFF GNUNET_TIME_relative_multiply ( \ + GNUNET_TIME_UNIT_MILLISECONDS, 100) + /** * Information about a fresh coin generated by the refresh * operation. @@ -119,6 +131,11 @@ struct RefreshMeltState */ struct GNUNET_TIME_Relative backoff; + /** + * How long did we wait in total for retries? + */ + struct GNUNET_TIME_Relative total_backoff; + /** * Number of bytes in @e refresh_data. */ @@ -201,6 +218,11 @@ struct RefreshRevealState */ struct GNUNET_TIME_Relative backoff; + /** + * How long did we wait in total for retries? + */ + struct GNUNET_TIME_Relative total_backoff; + /** * Number of fresh coins withdrawn, set by the * reveal callback as it comes from the exchange, @@ -251,6 +273,11 @@ struct RefreshLinkState */ struct GNUNET_TIME_Relative backoff; + /** + * How long did we wait in total for retries? + */ + struct GNUNET_TIME_Relative total_backoff; + /** * Expected HTTP response code. */ @@ -341,7 +368,10 @@ reveal_cb (void *cls, if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec) rrs->backoff = GNUNET_TIME_UNIT_ZERO; else - rrs->backoff = EXCHANGE_LIB_BACKOFF (rrs->backoff); + rrs->backoff = GNUNET_TIME_randomized_backoff (rrs->backoff, + MAX_BACKOFF); + rrs->total_backoff = GNUNET_TIME_relative_add (rrs->total_backoff, + rrs->backoff); rrs->retry_task = GNUNET_SCHEDULER_add_delayed (rrs->backoff, &do_reveal_retry, rrs); @@ -391,6 +421,14 @@ reveal_cb (void *cls, fc->sig.rsa_signature = GNUNET_CRYPTO_rsa_signature_dup (sigs[i].rsa_signature); } + if (0 != rrs->total_backoff.rel_value_us) + { + GNUNET_log (GNUNET_ERROR_TYPE_INFO, + "Total reveal backoff for %s was %s\n", + rrs->is->commands[rrs->is->ip].label, + GNUNET_STRINGS_relative_time_to_string (rrs->total_backoff, + GNUNET_YES)); + } break; default: GNUNET_log (GNUNET_ERROR_TYPE_WARNING, @@ -568,7 +606,10 @@ link_cb (void *cls, if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec) rls->backoff = GNUNET_TIME_UNIT_ZERO; else - rls->backoff = EXCHANGE_LIB_BACKOFF (rls->backoff); + rls->backoff = GNUNET_TIME_randomized_backoff (rls->backoff, + MAX_BACKOFF); + rls->total_backoff = GNUNET_TIME_relative_add (rls->total_backoff, + rls->backoff); rls->retry_task = GNUNET_SCHEDULER_add_delayed (rls->backoff, &do_link_retry, rls); @@ -663,6 +704,14 @@ link_cb (void *cls, TALER_TESTING_interpreter_fail (rls->is); return; } + if (0 != rls->total_backoff.rel_value_us) + { + GNUNET_log (GNUNET_ERROR_TYPE_INFO, + "Total link backoff for %s was %s\n", + rls->is->commands[rls->is->ip].label, + GNUNET_STRINGS_relative_time_to_string (rls->total_backoff, + GNUNET_YES)); + } break; default: GNUNET_log (GNUNET_ERROR_TYPE_ERROR, @@ -851,7 +900,10 @@ melt_cb (void *cls, if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec) rms->backoff = GNUNET_TIME_UNIT_ZERO; else - rms->backoff = EXCHANGE_LIB_BACKOFF (rms->backoff); + rms->backoff = GNUNET_TIME_randomized_backoff (rms->backoff, + MAX_BACKOFF); + rms->total_backoff = GNUNET_TIME_relative_add (rms->total_backoff, + rms->backoff); rms->retry_task = GNUNET_SCHEDULER_add_delayed (rms->backoff, &do_melt_retry, @@ -872,7 +924,14 @@ melt_cb (void *cls, return; } rms->noreveal_index = noreveal_index; - + if (0 != rms->total_backoff.rel_value_us) + { + GNUNET_log (GNUNET_ERROR_TYPE_INFO, + "Total melt backoff for %s was %s\n", + rms->is->commands[rms->is->ip].label, + GNUNET_STRINGS_relative_time_to_string (rms->total_backoff, + GNUNET_YES)); + } if (GNUNET_YES == rms->double_melt) { TALER_LOG_DEBUG ("Doubling the melt (%s)\n", diff --git a/src/testing/testing_api_cmd_stat.c b/src/testing/testing_api_cmd_stat.c new file mode 100644 index 000000000..3640490ce --- /dev/null +++ b/src/testing/testing_api_cmd_stat.c @@ -0,0 +1,190 @@ +/* + This file is part of TALER + (C) 2018 Taler Systems SA + + TALER is free software; you can redistribute it and/or modify + it under the terms of the GNU General Public License as + published by the Free Software Foundation; either version 3, or + (at your option) any later version. + + TALER is distributed in the hope that it will be useful, but + WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public + License along with TALER; see the file COPYING. If not, see + +*/ +/** + * @file testing/testing_api_cmd_stat.c + * @brief command(s) to get performance statistics on other commands + * @author Christian Grothoff + */ +#include "platform.h" +#include "taler_json_lib.h" +#include +#include "taler_testing_lib.h" + + +/** + * Cleanup the state from a "stat service" CMD. + * + * @param cls closure. + * @param cmd the command which is being cleaned up. + */ +static void +stat_cleanup (void *cls, + const struct TALER_TESTING_Command *cmd) +{ + (void) cls; + (void) cmd; + /* nothing to clean. */ + return; +} + + +/** + * No traits to offer, just provide a stub to be called when + * some CMDs iterates through the list of all the commands. + * + * @param cls closure. + * @param[out] ret result. + * @param trait name of the trait. + * @param index index number of the trait to return. + * @return #GNUNET_OK on success. + */ +static int +stat_traits (void *cls, + const void **ret, + const char *trait, + unsigned int index) +{ + (void) cls; + (void) ret; + (void) trait; + (void) index; + return GNUNET_NO; +} + + +/** + * Add the time @a cmd took to the respective duration in @a timings. + * + * @param timings where to add up times + * @param cmd command to evaluate + */ +static void +stat_cmd (struct TALER_TESTING_Timer *timings, + const struct TALER_TESTING_Command *cmd) +{ + struct GNUNET_TIME_Relative duration; + + if (cmd->start_time.abs_value_us > cmd->finish_time.abs_value_us) + { + GNUNET_break (0); + return; + } + duration = GNUNET_TIME_absolute_get_difference (cmd->start_time, + cmd->finish_time); + for (unsigned int i = 0; + NULL != timings[i].prefix; + i++) + { + if (0 == strncmp (timings[i].prefix, + cmd->label, + strlen (timings[i].prefix))) + { + timings[i].total_duration + = GNUNET_TIME_relative_add (duration, + timings[i].total_duration); + timings[i].num_commands++; + break; + } + } +} + + +/** + * Obtain statistics for @a timings of @a cmd + * + * @param timings what timings to get + * @param cmd command to process + */ +static void +do_stat (struct TALER_TESTING_Timer *timings, + const struct TALER_TESTING_Command *cmd) +{ + if (TALER_TESTING_cmd_is_batch (cmd)) + { +#define BATCH_INDEX 1 + struct TALER_TESTING_Command *bcmd; + + if (GNUNET_OK != + TALER_TESTING_get_trait_cmd (cmd, + BATCH_INDEX, + &bcmd)) + { + GNUNET_break (0); + return; + } + + for (unsigned int j = 0; NULL != bcmd[j].label; j++) + do_stat (timings, + &bcmd[j]); + } + else + { + stat_cmd (timings, + cmd); + } +} + + +/** + * Run a "stat" CMD. + * + * @param cls closure. + * @param cmd the command being run. + * @param is the interpreter state. + */ +static void +stat_run (void *cls, + const struct TALER_TESTING_Command *cmd, + struct TALER_TESTING_Interpreter *is) +{ + struct TALER_TESTING_Timer *timings = cls; + + for (unsigned int i = 0; NULL != is->commands[i].label; i++) + { + if (cmd == &is->commands[i]) + break; /* skip at our current command */ + do_stat (timings, + &is->commands[i]); + } + TALER_TESTING_interpreter_next (is); +} + + +/** + * Obtain performance data from the interpreter. + * + * @param timers what commands (by label) to obtain runtimes for + * @return the command + */ +struct TALER_TESTING_Command +TALER_TESTING_cmd_stat (struct TALER_TESTING_Timer *timers) +{ + struct TALER_TESTING_Command cmd = { + .label = "stat", + .run = stat_run, + .cleanup = stat_cleanup, + .traits = stat_traits, + .cls = (void *) timers + }; + + return cmd; +} + + +/* end of testing_api_cmd_sleep.c */ diff --git a/src/testing/testing_api_cmd_withdraw.c b/src/testing/testing_api_cmd_withdraw.c index b2fc272e3..1ef341e0a 100644 --- a/src/testing/testing_api_cmd_withdraw.c +++ b/src/testing/testing_api_cmd_withdraw.c @@ -40,6 +40,12 @@ * How long do we wait AT LEAST if the exchange says the reserve is unknown? */ #define UNKNOWN_MIN_BACKOFF GNUNET_TIME_relative_multiply ( \ + GNUNET_TIME_UNIT_MILLISECONDS, 10) + +/** + * How long do we wait AT MOST if the exchange says the reserve is unknown? + */ +#define UNKNOWN_MAX_BACKOFF GNUNET_TIME_relative_multiply ( \ GNUNET_TIME_UNIT_MILLISECONDS, 100) /** @@ -103,6 +109,11 @@ struct WithdrawState */ struct GNUNET_TIME_Relative backoff; + /** + * Total withdraw backoff applied. + */ + struct GNUNET_TIME_Relative total_backoff; + /** * Expected HTTP response code to the request. */ @@ -193,6 +204,10 @@ reserve_withdraw_cb (void *cls, else ws->backoff = GNUNET_TIME_relative_max (UNKNOWN_MIN_BACKOFF, ws->backoff); + ws->backoff = GNUNET_TIME_relative_min (ws->backoff, + UNKNOWN_MAX_BACKOFF); + ws->total_backoff = GNUNET_TIME_relative_add (ws->total_backoff, + ws->backoff); ws->retry_task = GNUNET_SCHEDULER_add_delayed (ws->backoff, &do_retry, ws); @@ -224,6 +239,14 @@ reserve_withdraw_cb (void *cls, } ws->sig.rsa_signature = GNUNET_CRYPTO_rsa_signature_dup (sig->rsa_signature); + if (0 != ws->total_backoff.rel_value_us) + { + GNUNET_log (GNUNET_ERROR_TYPE_INFO, + "Total withdraw backoff for %s was %s\n", + is->commands[is->ip].label, + GNUNET_STRINGS_relative_time_to_string (ws->total_backoff, + GNUNET_YES)); + } break; case MHD_HTTP_FORBIDDEN: /* nothing to check */ diff --git a/src/testing/testing_api_loop.c b/src/testing/testing_api_loop.c index 1053e6f78..33b5cf077 100644 --- a/src/testing/testing_api_loop.c +++ b/src/testing/testing_api_loop.c @@ -169,9 +169,14 @@ TALER_TESTING_interpreter_next (struct TALER_TESTING_Interpreter *is) if (GNUNET_SYSERR == is->result) return; /* ignore, we already failled! */ if (TALER_TESTING_cmd_is_batch (cmd)) + { TALER_TESTING_cmd_batch_next (is); + } else + { + cmd->finish_time = GNUNET_TIME_absolute_get (); is->ip++; + } if (0 == (ipc % 1000)) { if (0 != ipc) @@ -267,7 +272,7 @@ interpreter_run (void *cls) GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Running command `%s'\n", cmd->label); - + cmd->start_time = GNUNET_TIME_absolute_get (); cmd->run (cmd->cls, cmd, is); -- cgit v1.2.3