nuke some console.log statements, test wallet testing functionality in integration test

9 files changed, 80 insertions, 73 deletions

diff --git a/packages/taler-wallet-core/src/operations/exchanges.ts b/packages/taler-wallet-core/src/operations/exchanges.ts
index a7771f6d2..d40dd7883 100644
--- a/packages/taler-wallet-core/src/operations/exchanges.ts
+++ b/packages/taler-wallet-core/src/operations/exchanges.ts
@@ -175,7 +175,7 @@ async function updateExchangeWithKeys(
     async (tx) => {
       const r = await tx.get(Stores.exchanges, baseUrl);
       if (!r) {
-        console.warn(`exchange ${baseUrl} no longer present`);
+        logger.warn(`exchange ${baseUrl} no longer present`);
         return;
       }
       if (r.details) {
@@ -222,10 +222,10 @@ async function updateExchangeWithKeys(
         if (oldDenom.isRevoked) {
           // We already marked the denomination as revoked,
           // this implies we revoked all coins
-          console.log("denom already revoked");
+          logger.trace("denom already revoked");
           continue;
         }
-        console.log("revoking denom", recoupInfo.h_denom_pub);
+        logger.trace("revoking denom", recoupInfo.h_denom_pub);
         oldDenom.isRevoked = true;
         await tx.put(Stores.denominations, oldDenom);
         const affectedCoins = await tx
@@ -236,7 +236,7 @@ async function updateExchangeWithKeys(
         }
       }
       if (newlyRevokedCoinPubs.length != 0) {
-        console.log("recouping coins", newlyRevokedCoinPubs);
+        logger.trace("recouping coins", newlyRevokedCoinPubs);
         await createRecoupGroup(ws, tx, newlyRevokedCoinPubs);
       }
     },
@@ -246,7 +246,7 @@ async function updateExchangeWithKeys(
     // Asynchronously start recoup.  This doesn't need to finish
     // for the exchange update to be considered finished.
     processRecoupGroup(ws, recoupGroupId).catch((e) => {
-      console.log("error while recouping coins:", e);
+      logger.error("error while recouping coins:", e);
     });
   }
 
diff --git a/packages/taler-wallet-core/src/operations/pay.ts b/packages/taler-wallet-core/src/operations/pay.ts
index 0576f7eab..c3dd6c6d3 100644
--- a/packages/taler-wallet-core/src/operations/pay.ts
+++ b/packages/taler-wallet-core/src/operations/pay.ts
@@ -353,7 +353,7 @@ async function getCoinsForPayment(
         throw Error("db inconsistent");
       }
       if (denom.value.currency !== currency) {
-        console.warn(
+        logger.warn(
           `same pubkey for different currencies at exchange ${exchange.baseUrl}`,
         );
         continue;
@@ -539,7 +539,7 @@ async function incrementPurchasePayRetry(
   proposalId: string,
   err: OperationErrorDetails | undefined,
 ): Promise<void> {
-  console.log("incrementing purchase pay retry with error", err);
+  logger.warn("incrementing purchase pay retry with error", err);
   await ws.db.runWithWriteTransaction([Stores.purchases], async (tx) => {
     const pr = await tx.get(Stores.purchases, proposalId);
     if (!pr) {
@@ -693,7 +693,7 @@ async function processDownloadProposalImpl(
           fulfillmentUrl,
         );
         if (differentPurchase) {
-          console.log("repurchase detected");
+          logger.warn("repurchase detected");
           p.proposalStatus = ProposalStatus.REPURCHASE;
           p.repurchaseProposalId = differentPurchase.proposalId;
           await tx.put(Stores.proposals, p);
@@ -814,7 +814,7 @@ export async function submitPay(
     merchantPub,
   );
   if (!valid) {
-    console.error("merchant payment signature invalid");
+    logger.error("merchant payment signature invalid");
     // FIXME: properly display error
     throw Error("merchant payment signature invalid");
   }
@@ -826,7 +826,7 @@ export async function submitPay(
   if (isFirst) {
     const ar = purchase.contractData.autoRefund;
     if (ar) {
-      console.log("auto_refund present");
+      logger.info("auto_refund present");
       purchase.refundStatusRequested = true;
       purchase.refundStatusRetryInfo = initRetryInfo();
       purchase.lastRefundStatusError = undefined;
@@ -899,7 +899,7 @@ export async function preparePayForUri(
     if (!existingProposalId) {
       throw Error("invalid proposal state");
     }
-    console.log("using existing purchase for same product");
+    logger.trace("using existing purchase for same product");
     proposal = await ws.db.get(Stores.proposals, existingProposalId);
     if (!proposal) {
       throw Error("existing proposal is in wrong state");
@@ -907,7 +907,7 @@ export async function preparePayForUri(
   }
   const d = proposal.download;
   if (!d) {
-    console.error("bad proposal", proposal);
+    logger.error("bad proposal", proposal);
     throw Error("proposal is in invalid state");
   }
   const contractData = d.contractData;
diff --git a/packages/taler-wallet-core/src/operations/recoup.ts b/packages/taler-wallet-core/src/operations/recoup.ts
index cc91ab0e9..f855a28cb 100644
--- a/packages/taler-wallet-core/src/operations/recoup.ts
+++ b/packages/taler-wallet-core/src/operations/recoup.ts
@@ -51,6 +51,9 @@ import { getTimestampNow } from "../util/time";
 import { guardOperationException } from "./errors";
 import { readSuccessResponseJsonOrThrow } from "../util/http";
 import { URL } from "../util/url";
+import { Logger } from "../util/logging";
+
+const logger = new Logger("operations/recoup.ts");
 
 async function incrementRecoupRetry(
   ws: InternalWalletState,
@@ -207,7 +210,7 @@ async function recoupWithdrawCoin(
   });
 
   forceQueryReserve(ws, reserve.reservePub).catch((e) => {
-    console.log("re-querying reserve after recoup failed:", e);
+    logger.error("re-querying reserve after recoup failed:", e);
   });
 }
 
@@ -224,7 +227,7 @@ async function recoupRefreshCoin(
 
   const recoupRequest = await ws.cryptoApi.createRecoupRequest(coin);
   const reqUrl = new URL(`/coins/${coin.coinPub}/recoup`, coin.exchangeBaseUrl);
-  console.log("making recoup request");
+  logger.trace("making recoup request");
 
   const resp = await ws.http.postJson(reqUrl.href, recoupRequest);
   const recoupConfirmation = await readSuccessResponseJsonOrThrow(
@@ -270,7 +273,7 @@ async function recoupRefreshCoin(
         oldCoin.currentAmount,
         recoupGroup.oldAmountPerCoin[coinIdx],
       ).amount;
-      console.log(
+      logger.trace(
         "recoup: setting old coin amount to",
         Amounts.stringify(oldCoin.currentAmount),
       );
@@ -317,14 +320,12 @@ async function processRecoupGroupImpl(
   if (forceNow) {
     await resetRecoupGroupRetry(ws, recoupGroupId);
   }
-  console.log("in processRecoupGroupImpl");
   const recoupGroup = await ws.db.get(Stores.recoupGroups, recoupGroupId);
   if (!recoupGroup) {
     return;
   }
-  console.log(recoupGroup);
   if (recoupGroup.timestampFinished) {
-    console.log("recoup group finished");
+    logger.trace("recoup group finished");
     return;
   }
   const ps = recoupGroup.coinPubs.map((x, i) =>
diff --git a/packages/taler-wallet-core/src/operations/refresh.ts b/packages/taler-wallet-core/src/operations/refresh.ts
index 646bc2edf..52325281b 100644
--- a/packages/taler-wallet-core/src/operations/refresh.ts
+++ b/packages/taler-wallet-core/src/operations/refresh.ts
@@ -188,7 +188,7 @@ async function refreshCreateSession(
       }
       const r = Amounts.sub(c.currentAmount, refreshSession.amountRefreshInput);
       if (r.saturated) {
-        console.log("can't refresh coin, no amount left");
+        logger.warn("can't refresh coin, no amount left");
         return;
       }
       c.currentAmount = r.amount;
@@ -387,7 +387,7 @@ async function refreshReveal(
     async (tx) => {
       const rg = await tx.get(Stores.refreshGroups, refreshGroupId);
       if (!rg) {
-        console.log("no refresh session found");
+        logger.warn("no refresh session found");
         return;
       }
       const rs = rg.refreshSessionPerCoin[coinIndex];
@@ -395,7 +395,7 @@ async function refreshReveal(
         return;
       }
       if (rs.finishedTimestamp) {
-        console.log("refresh session already finished");
+        logger.warn("refresh session already finished");
         return;
       }
       rs.finishedTimestamp = getTimestampNow();
@@ -417,7 +417,7 @@ async function refreshReveal(
       await tx.put(Stores.refreshGroups, rg);
     },
   );
-  console.log("refresh finished (end of reveal)");
+  logger.trace("refresh finished (end of reveal)");
   ws.notify({
     type: NotificationType.RefreshRevealed,
   });
diff --git a/packages/taler-wallet-core/src/operations/refund.ts b/packages/taler-wallet-core/src/operations/refund.ts
index 9ee71012e..fb39aa638 100644
--- a/packages/taler-wallet-core/src/operations/refund.ts
+++ b/packages/taler-wallet-core/src/operations/refund.ts
@@ -50,7 +50,7 @@ import {
   AmountString,
 } from "../types/talerTypes";
 import { guardOperationException } from "./errors";
-import { getTimestampNow } from "../util/time";
+import { getTimestampNow, Timestamp } from "../util/time";
 import { Logger } from "../util/logging";
 import { readSuccessResponseJsonOrThrow } from "../util/http";
 import { TransactionHandle } from "../util/query";
@@ -142,6 +142,7 @@ async function applySuccessfulRefund(
 
   p.refunds[refundKey] = {
     type: RefundState.Applied,
+    obtainedTime: getTimestampNow(),
     executionTime: r.execution_time,
     refundAmount: Amounts.parseOrThrow(r.refund_amount),
     refundFee: denom.feeRefund,
@@ -191,6 +192,7 @@ async function storePendingRefund(
 
   p.refunds[refundKey] = {
     type: RefundState.Pending,
+    obtainedTime: getTimestampNow(),
     executionTime: r.execution_time,
     refundAmount: Amounts.parseOrThrow(r.refund_amount),
     refundFee: denom.feeRefund,
diff --git a/packages/taler-wallet-core/src/operations/reserves.ts b/packages/taler-wallet-core/src/operations/reserves.ts
index 060226cab..fb525da45 100644
--- a/packages/taler-wallet-core/src/operations/reserves.ts
+++ b/packages/taler-wallet-core/src/operations/reserves.ts
@@ -178,7 +178,7 @@ export async function createReserve(
   const exchangeInfo = await updateExchangeFromUrl(ws, req.exchange);
   const exchangeDetails = exchangeInfo.details;
   if (!exchangeDetails) {
-    console.log(exchangeDetails);
+    logger.trace(exchangeDetails);
     throw Error("exchange not updated");
   }
   const { isAudited, isTrusted } = await getExchangeTrust(ws, exchangeInfo);
@@ -576,7 +576,7 @@ async function processReserveImpl(
 ): Promise<void> {
   const reserve = await ws.db.get(Stores.reserves, reservePub);
   if (!reserve) {
-    console.log("not processing reserve: reserve does not exist");
+    logger.trace("not processing reserve: reserve does not exist");
     return;
   }
   if (!forceNow) {
diff --git a/packages/taler-wallet-core/src/operations/testing.ts b/packages/taler-wallet-core/src/operations/testing.ts
index 629cd92ff..f1b2d98ff 100644
--- a/packages/taler-wallet-core/src/operations/testing.ts
+++ b/packages/taler-wallet-core/src/operations/testing.ts
@@ -269,11 +269,11 @@ async function makePayment(
     "taler://fulfillment-success/thx",
   );
 
-  console.log("created order with orderId", orderResp.orderId);
+  logger.trace("created order with orderId", orderResp.orderId);
 
   let paymentStatus = await checkPayment(http, merchant, orderResp.orderId);
 
-  console.log("payment status", paymentStatus);
+  logger.trace("payment status", paymentStatus);
 
   const talerPayUri = paymentStatus.taler_pay_uri;
   if (!talerPayUri) {
@@ -282,7 +282,7 @@ async function makePayment(
 
   const preparePayResult = await wallet.preparePayForUri(talerPayUri);
 
-  console.log("prepare pay result", preparePayResult);
+  logger.trace("prepare pay result", preparePayResult);
 
   if (preparePayResult.status != "payment-possible") {
     throw Error("payment not possible");
@@ -293,11 +293,11 @@ async function makePayment(
     undefined,
   );
 
-  console.log("confirmPayResult", confirmPayResult);
+  logger.trace("confirmPayResult", confirmPayResult);
 
   paymentStatus = await checkPayment(http, merchant, orderResp.orderId);
 
-  console.log("payment status after wallet payment:", paymentStatus);
+  logger.trace("payment status after wallet payment:", paymentStatus);
 
   if (paymentStatus.order_status !== "paid") {
     throw Error("payment did not succeed");
@@ -318,26 +318,18 @@ export async function runIntegrationTest(
   const parsedSpendAmount = Amounts.parseOrThrow(args.amountToSpend);
   const currency = parsedSpendAmount.currency;
 
-  const myHttpLib = new NodeHttpLib();
-  myHttpLib.setThrottling(false);
-
-  const myWallet = await getDefaultNodeWallet({ httpLib: myHttpLib });
-
-  myWallet.runRetryLoop().catch((e) => {
-    console.error("exception during retry loop:", e);
-  });
-
   logger.info("withdrawing test balance");
-  await wallet.withdrawTestBalance(
-    args.amountToWithdraw,
-    args.bankBaseUrl,
-    args.exchangeBaseUrl,
-  );
+  await wallet.withdrawTestBalance({
+    amount: args.amountToWithdraw,
+    bankBaseUrl: args.bankBaseUrl,
+    exchangeBaseUrl: args.exchangeBaseUrl,
+  });
+  await wallet.runUntilDone();
   logger.info("done withdrawing test balance");
 
-  const balance = await myWallet.getBalances();
+  const balance = await wallet.getBalances();
 
-  console.log(JSON.stringify(balance, null, 2));
+  logger.trace(JSON.stringify(balance, null, 2));
 
   const myMerchant: MerchantBackendInfo = {
     baseUrl: args.merchantBaseUrl,
@@ -353,26 +345,26 @@ export async function runIntegrationTest(
   );
 
   // Wait until the refresh is done
-  await myWallet.runUntilDone();
+  await wallet.runUntilDone();
 
-  console.log("withdrawing test balance for refund");
+  logger.trace("withdrawing test balance for refund");
   const withdrawAmountTwo = Amounts.parseOrThrow(`${currency}:18`);
   const spendAmountTwo = Amounts.parseOrThrow(`${currency}:7`);
   const refundAmount = Amounts.parseOrThrow(`${currency}:6`);
   const spendAmountThree = Amounts.parseOrThrow(`${currency}:3`);
 
-  await myWallet.withdrawTestBalance(
-    Amounts.stringify(withdrawAmountTwo),
-    args.bankBaseUrl,
-    args.exchangeBaseUrl,
-  );
+  await wallet.withdrawTestBalance({
+    amount: Amounts.stringify(withdrawAmountTwo),
+    bankBaseUrl: args.bankBaseUrl,
+    exchangeBaseUrl: args.exchangeBaseUrl,
+  });
 
   // Wait until the withdraw is done
-  await myWallet.runUntilDone();
+  await wallet.runUntilDone();
 
   const { orderId: refundOrderId } = await makePayment(
     http,
-    myWallet,
+    wallet,
     myMerchant,
     Amounts.stringify(spendAmountTwo),
     "order that will be refunded",
@@ -386,22 +378,30 @@ export async function runIntegrationTest(
     Amounts.stringify(refundAmount),
   );
 
-  console.log("refund URI", refundUri);
+  logger.trace("refund URI", refundUri);
 
-  await myWallet.applyRefund(refundUri);
+  await wallet.applyRefund(refundUri);
+
+  logger.trace("integration test: applied refund");
 
   // Wait until the refund is done
-  await myWallet.runUntilDone();
+  await wallet.runUntilDone();
+
+  logger.trace("integration test: making payment after refund");
 
   await makePayment(
     http,
-    myWallet,
+    wallet,
     myMerchant,
     Amounts.stringify(spendAmountThree),
     "payment after refund",
   );
 
-  await myWallet.runUntilDone();
+  logger.trace("integration test: make payment done");
+
+  await wallet.runUntilDone();
+
+  logger.trace("integration test: all done!");
 }
 
 export async function testPay(
@@ -409,8 +409,8 @@ export async function testPay(
   wallet: Wallet,
   args: TestPayArgs,
 ) {
-  console.log("creating order");
-  const merchant = { apikey: args.apikey, baseUrl: args.merchant };
+  logger.trace("creating order");
+  const merchant = { apikey: args.merchantApiKey, baseUrl: args.merchantBaseUrl };
   const orderResp = await createOrder(
     http,
     merchant,
@@ -418,7 +418,7 @@ export async function testPay(
     args.summary,
     "taler://fulfillment-success/thank+you",
   );
-  console.log("created new order with order ID", orderResp.orderId);
+  logger.trace("created new order with order ID", orderResp.orderId);
   const checkPayResp = await checkPayment(http, merchant, orderResp.orderId);
   const talerPayUri = checkPayResp.taler_pay_uri;
   if (!talerPayUri) {
@@ -426,7 +426,7 @@ export async function testPay(
     process.exit(1);
     return;
   }
-  console.log("taler pay URI:", talerPayUri);
+  logger.trace("taler pay URI:", talerPayUri);
   const result = await wallet.preparePayForUri(talerPayUri);
   if (result.status !== PreparePayResultType.PaymentPossible) {
     throw Error(`unexpected prepare pay status: ${result.status}`);
diff --git a/packages/taler-wallet-core/src/operations/tip.ts b/packages/taler-wallet-core/src/operations/tip.ts
index 84cfa570a..6dee9c87e 100644
--- a/packages/taler-wallet-core/src/operations/tip.ts
+++ b/packages/taler-wallet-core/src/operations/tip.ts
@@ -45,6 +45,9 @@ import { NotificationType } from "../types/notifications";
 import { getTimestampNow } from "../util/time";
 import { readSuccessResponseJsonOrThrow } from "../util/http";
 import { URL } from "../util/url";
+import { Logger } from "../util/logging";
+
+const logger = new Logger("operations/tip.ts");
 
 export async function getTipStatus(
   ws: InternalWalletState,
@@ -57,13 +60,13 @@ export async function getTipStatus(
 
   const tipStatusUrl = new URL("tip-pickup", res.merchantBaseUrl);
   tipStatusUrl.searchParams.set("tip_id", res.merchantTipId);
-  console.log("checking tip status from", tipStatusUrl.href);
+  logger.trace("checking tip status from", tipStatusUrl.href);
   const merchantResp = await ws.http.get(tipStatusUrl.href);
   const tipPickupStatus = await readSuccessResponseJsonOrThrow(
     merchantResp,
     codecForTipPickupGetResponse(),
   );
-  console.log("status", tipPickupStatus);
+  logger.trace(`status ${tipPickupStatus}`);
 
   const amount = Amounts.parseOrThrow(tipPickupStatus.amount);
 
@@ -191,7 +194,7 @@ async function processTipImpl(
   }
 
   if (tipRecord.pickedUp) {
-    console.log("tip already picked up");
+    logger.warn("tip already picked up");
     return;
   }
 
@@ -230,7 +233,7 @@ async function processTipImpl(
     throw Error("invariant violated");
   }
 
-  console.log("got planchets for tip!");
+  logger.trace("got planchets for tip!");
 
   // Planchets in the form that the merchant expects
   const planchetsDetail: TipPlanchetDetail[] = tipRecord.planchets.map((p) => ({
@@ -248,9 +251,9 @@ async function processTipImpl(
     if (merchantResp.status !== 200) {
       throw Error(`unexpected status ${merchantResp.status} for tip-pickup`);
     }
-    console.log("got merchant resp:", merchantResp);
+    logger.trace("got merchant resp:", merchantResp);
   } catch (e) {
-    console.log("tipping failed", e);
+    logger.warn("tipping failed", e);
     throw e;
   }
 
@@ -331,7 +334,7 @@ export async function acceptTip(
 ): Promise<void> {
   const tipRecord = await ws.db.get(Stores.tips, tipId);
   if (!tipRecord) {
-    console.log("tip not found");
+    logger.error("tip not found");
     return;
   }
 
diff --git a/packages/taler-wallet-core/src/operations/transactions.ts b/packages/taler-wallet-core/src/operations/transactions.ts
index 5521dda90..e17dfac3a 100644
--- a/packages/taler-wallet-core/src/operations/transactions.ts
+++ b/packages/taler-wallet-core/src/operations/transactions.ts
@@ -25,7 +25,7 @@ import {
   RefundState,
 } from "../types/dbTypes";
 import { Amounts, AmountJson } from "../util/amounts";
-import { timestampCmp } from "../util/time";
+import { timestampCmp, Timestamp } from "../util/time";
 import {
   TransactionsRequest,
   TransactionsResponse,
@@ -297,12 +297,13 @@ export async function getTransactions(
           if (!r0) {
             throw Error("invariant violated");
           }
+          let ts: Timestamp;
           transactions.push({
             type: TransactionType.Refund,
             info,
             refundedTransactionId: paymentTransactionId,
             transactionId: refundTransactionId,
-            timestamp: r0.executionTime,
+            timestamp: r0.obtainedTime,
             amountEffective: Amounts.stringify(amountEffective),
             amountRaw: Amounts.stringify(amountRaw),
             pending: false,