test error handling

This commit is contained in:
Florian Dold 2020-09-01 18:00:46 +05:30
parent 5e7149f79e
commit 5056da6548
No known key found for this signature in database
GPG Key ID: D2E4F00F29D02A4B
16 changed files with 278 additions and 84 deletions

View File

@ -133,6 +133,62 @@ export async function sh(
});
}
function shellescape(args: string[]) {
const ret = args.map((s) => {
if (/[^A-Za-z0-9_\/:=-]/.test(s)) {
s = "'" + s.replace(/'/g, "'\\''") + "'";
s = s.replace(/^(?:'')+/g, "").replace(/\\'''/g, "\\'");
}
return s;
});
return ret.join(" ");
}
/**
* Run a shell command, return stdout.
*
* Log stderr to a log file.
*/
export async function runCommand(
t: GlobalTestState,
logName: string,
command: string,
args: string[],
): Promise<string> {
console.log("runing command", shellescape([command, ...args]));
return new Promise((resolve, reject) => {
const stdoutChunks: Buffer[] = [];
const proc = spawn(command, args, {
stdio: ["inherit", "pipe", "pipe"],
shell: false,
});
proc.stdout.on("data", (x) => {
if (x instanceof Buffer) {
stdoutChunks.push(x);
} else {
throw Error("unexpected data chunk type");
}
});
const stderrLogFileName = path.join(t.testDir, `${logName}-stderr.log`);
const stderrLog = fs.createWriteStream(stderrLogFileName, {
flags: "a",
});
proc.stderr.pipe(stderrLog);
proc.on("exit", (code, signal) => {
console.log(`child process exited (${code} / ${signal})`);
if (code != 0) {
reject(Error(`Unexpected exit code ${code} for '${command}'`));
return;
}
const b = Buffer.concat(stdoutChunks).toString("utf-8");
resolve(b);
});
proc.on("error", () => {
reject(Error("Child process had error"));
});
});
}
export class ProcessWrapper {
private waitPromise: Promise<WaitResult>;
constructor(public proc: ChildProcess) {
@ -298,7 +354,7 @@ export class GlobalTestState {
}
}
assertDeepEqual(actual: any, expected: any): asserts actual is any {
assertDeepEqual<T>(actual: any, expected: T): asserts actual is T {
deepStrictEqual(actual, expected);
}
@ -349,7 +405,9 @@ export class GlobalTestState {
args: string[],
logName: string,
): ProcessWrapper {
console.log(`spawning process ${command} with arguments ${args})`);
console.log(
`spawning process (${logName}): ${shellescape([command, ...args])}`,
);
const proc = spawn(command, args, {
stdio: ["inherit", "pipe", "pipe"],
});
@ -1028,8 +1086,8 @@ export class ExchangeService implements ExchangeServiceInterface {
await sh(
this.globalState,
"exchange-wire",
`taler-exchange-wire ${this.timetravelArg} -c "${this.configFilename}"`
)
`taler-exchange-wire ${this.timetravelArg} -c "${this.configFilename}"`,
);
this.exchangeWirewatchProc = this.globalState.spawnService(
"taler-exchange-wirewatch",
@ -1403,6 +1461,14 @@ export class WalletCli {
fs.unlinkSync(this.dbfile);
}
private get timetravelArgArr(): string[] {
const tta = this.timetravelArg;
if (tta) {
return [tta];
}
return [];
}
async apiRequest(
request: string,
payload: unknown,
@ -1420,13 +1486,19 @@ export class WalletCli {
return JSON.parse(resp) as CoreApiResponse;
}
async runUntilDone(): Promise<void> {
await sh(
async runUntilDone(args: { maxRetries?: number } = {}): Promise<void> {
await runCommand(
this.globalTestState,
`wallet-${this.name}`,
`taler-wallet-cli ${this.timetravelArg ?? ""} --no-throttle --wallet-db ${
this.dbfile
} run-until-done`,
"taler-wallet-cli",
[
"--no-throttle",
...this.timetravelArgArr,
"--wallet-db",
this.dbfile,
"run-until-done",
...(args.maxRetries ? ["--max-retries", `${args.maxRetries}`] : []),
],
);
}

View File

@ -221,7 +221,7 @@ export async function createFaultInjectedMerchantTestkudosEnvironment(
/**
* Withdraw balance.
*/
export async function withdrawViaBank(
export async function startWithdrawViaBank(
t: GlobalTestState,
p: {
wallet: WalletCli;
@ -255,6 +255,26 @@ export async function withdrawViaBank(
talerWithdrawUri: wop.taler_withdraw_uri,
});
t.assertTrue(r2.type === "response");
}
/**
* Withdraw balance.
*/
export async function withdrawViaBank(
t: GlobalTestState,
p: {
wallet: WalletCli;
bank: BankService;
exchange: ExchangeService;
amount: AmountString;
},
): Promise<void> {
const { wallet } = p;
await startWithdrawViaBank(t, p);
await wallet.runUntilDone();
// Check balance

View File

@ -177,7 +177,7 @@ runTest(async (t: GlobalTestState) => {
// Response is malformed, since it didn't even contain a version code
// in a format the wallet can understand.
t.assertTrue(
err1.operationError.talerErrorCode ===
err1.operationError.code ===
TalerErrorCode.WALLET_RECEIVED_MALFORMED_RESPONSE,
);
@ -214,7 +214,7 @@ runTest(async (t: GlobalTestState) => {
});
t.assertTrue(
err2.operationError.talerErrorCode ===
err2.operationError.code ===
TalerErrorCode.WALLET_EXCHANGE_PROTOCOL_VERSION_INCOMPATIBLE,
);

View File

@ -102,7 +102,7 @@ runTest(async (t: GlobalTestState) => {
});
t.assertTrue(
err.operationError.talerErrorCode ===
err.operationError.code ===
TalerErrorCode.WALLET_ORDER_ALREADY_CLAIMED,
);

View File

@ -17,9 +17,18 @@
/**
* Imports.
*/
import { runTest, GlobalTestState, MerchantPrivateApi, WalletCli } from "./harness";
import { createSimpleTestkudosEnvironment, withdrawViaBank } from "./helpers";
import { PreparePayResultType, durationMin, Duration } from "taler-wallet-core";
import {
runTest,
GlobalTestState,
MerchantPrivateApi,
WalletCli,
} from "./harness";
import {
createSimpleTestkudosEnvironment,
withdrawViaBank,
startWithdrawViaBank,
} from "./helpers";
import { PreparePayResultType, durationMin, Duration, TransactionType } from "taler-wallet-core";
/**
* Basic time travel test.
@ -36,7 +45,7 @@ runTest(async (t: GlobalTestState) => {
// Withdraw digital cash into the wallet.
await withdrawViaBank(t, { wallet, bank, exchange, amount: "TESTKUDOS:20" });
await withdrawViaBank(t, { wallet, bank, exchange, amount: "TESTKUDOS:15" });
// Travel 400 days into the future,
// as the deposit expiration is two years
@ -56,9 +65,28 @@ runTest(async (t: GlobalTestState) => {
await merchant.pingUntilAvailable();
// This should fail, as the wallet didn't time travel yet.
await withdrawViaBank(t, { wallet, bank, exchange, amount: "TESTKUDOS:20" });
await startWithdrawViaBank(t, {
wallet,
bank,
exchange,
amount: "TESTKUDOS:20",
});
const bal = await wallet.getBalances();
// Check that transactions are correct for the failed withdrawal
{
await wallet.runUntilDone({ maxRetries: 5 });
const transactions = await wallet.getTransactions();
console.log(transactions);
const types = transactions.transactions.map((x) => x.type);
t.assertDeepEqual(types, ["withdrawal", "withdrawal"]);
const wtrans = transactions.transactions[0];
t.assertTrue(wtrans.type === TransactionType.Withdrawal);
t.assertTrue(wtrans.pending);
}
console.log(bal);
// Now we also let the wallet time travel
wallet.setTimetravel(timetravelDuration);
await wallet.runUntilDone({ maxRetries: 5 });
});

View File

@ -59,7 +59,7 @@ runTest(async (t: GlobalTestState) => {
});
t.assertTrue(r2.type === "error");
t.assertTrue(
r2.error.talerErrorCode ===
r2.error.code ===
TalerErrorCode.WALLET_WITHDRAWAL_OPERATION_ABORTED_BY_BANK,
);

View File

@ -262,9 +262,13 @@ walletCli
.subcommand("finishPendingOpt", "run-until-done", {
help: "Run until no more work is left.",
})
.maybeOption("maxRetries", ["--max-retries"], clk.INT)
.action(async (args) => {
await withWallet(args, async (wallet) => {
await wallet.runUntilDoneAndStop();
await wallet.runUntilDone({
maxRetries: args.finishPendingOpt.maxRetries,
});
wallet.stop();
});
});

View File

@ -969,6 +969,13 @@ export enum TalerErrorCode {
*/
REFUND_INVALID_FAILURE_PROOF_BY_EXCHANGE = 1516,
/**
* The exchange failed to lookup information for the refund from its database.
* Returned with an HTTP status code of #MHD_HTTP_INTERNAL_SERVER_ERROR (500).
* (A value of 0 indicates that the error is generated client-side).
*/
REFUND_DATABASE_LOOKUP_ERROR = 1517,
/**
* The wire format specified in the "sender_account_details" is not understood or not supported by this exchange.
* Returned with an HTTP status code of #MHD_HTTP_NOT_FOUND (404).
@ -1571,6 +1578,20 @@ export enum TalerErrorCode {
*/
FORGET_PATH_NOT_FORGETTABLE = 2182,
/**
* The merchant backend cannot forget part of an order because it failed to start the database transaction.
* Returned with an HTTP status code of #MHD_HTTP_INTERNAL_SERVER_ERROR (500).
* (A value of 0 indicates that the error is generated client-side).
*/
FORGET_ORDER_DB_START_ERROR = 2183,
/**
* The merchant backend cannot forget part of an order because it failed to commit the database transaction.
* Returned with an HTTP status code of #MHD_HTTP_INTERNAL_SERVER_ERROR (500).
* (A value of 0 indicates that the error is generated client-side).
*/
FORGET_ORDER_DB_COMMIT_ERROR = 2184,
/**
* Integer overflow with specified timestamp argument detected.
* Returned with an HTTP status code of #MHD_HTTP_BAD_REQUEST (400).
@ -1991,6 +2012,13 @@ export enum TalerErrorCode {
*/
ORDERS_ALREADY_CLAIMED = 2521,
/**
* The merchant backend couldn't find a product with the specified id.
* Returned with an HTTP status code of #MHD_HTTP_NOT_FOUND (404).
* (A value of 0 indicates that the error is generated client-side).
*/
GET_PRODUCTS_NOT_FOUND = 2549,
/**
* The merchant backend failed to lookup the products.
* Returned with an HTTP status code of #MHD_HTTP_INTERNAL_SERVER_ERROR (500).
@ -2983,7 +3011,7 @@ export enum TalerErrorCode {
* Returned with an HTTP status code of #MHD_HTTP_INTERNAL_SERVER_ERROR (500).
* (A value of 0 indicates that the error is generated client-side).
*/
SYNC_DB_FETCH_ERROR = 6000,
SYNC_DB_HARD_FETCH_ERROR = 6000,
/**
* The sync service failed find the record in its database.
@ -3028,11 +3056,11 @@ export enum TalerErrorCode {
SYNC_INVALID_SIGNATURE = 6007,
/**
* The "Content-length" field for the upload is either not a number, or too big, or missing.
* The "Content-length" field for the upload is either not a number, or too big.
* Returned with an HTTP status code of #MHD_HTTP_BAD_REQUEST (400).
* (A value of 0 indicates that the error is generated client-side).
*/
SYNC_BAD_CONTENT_LENGTH = 6008,
SYNC_MALFORMED_CONTENT_LENGTH = 6008,
/**
* The "Content-length" field for the upload is too big based on the server's terms of service.
@ -3111,6 +3139,27 @@ export enum TalerErrorCode {
*/
SYNC_PREVIOUS_BACKUP_UNKNOWN = 6019,
/**
* The sync service had a serialization failure when accessing its database.
* Returned with an HTTP status code of #MHD_HTTP_INTERNAL_SERVER_ERROR (500).
* (A value of 0 indicates that the error is generated client-side).
*/
SYNC_DB_SOFT_FETCH_ERROR = 6020,
/**
* The sync service first found information, and then later not. This could happen if a backup was garbage collected just when it was being accessed. Trying again may give a different answer.
* Returned with an HTTP status code of #MHD_HTTP_INTERNAL_SERVER_ERROR (500).
* (A value of 0 indicates that the error is generated client-side).
*/
SYNC_DB_INCONSISTENT_FETCH_ERROR = 6021,
/**
* The "Content-length" field for the upload is missing.
* Returned with an HTTP status code of #MHD_HTTP_BAD_REQUEST (400).
* (A value of 0 indicates that the error is generated client-side).
*/
SYNC_MISSING_CONTENT_LENGTH = 6022,
/**
* The wallet does not implement a version of the exchange protocol that is compatible with the protocol version of the exchange.
* Returned with an HTTP status code of #MHD_HTTP_NOT_IMPLEMENTED (501).
@ -3216,6 +3265,13 @@ export enum TalerErrorCode {
*/
WALLET_ORDER_ALREADY_CLAIMED = 7014,
/**
* A group of withdrawal operations (typically for the same reserve at the same exchange) has errors and will be tried again later.
* Returned with an HTTP status code of #MHD_HTTP_UNINITIALIZED (0).
* (A value of 0 indicates that the error is generated client-side).
*/
WALLET_WITHDRAWAL_GROUP_INCOMPLETE = 7015,
/**
* End of error code range.
* Returned with an HTTP status code of #MHD_HTTP_UNINITIALIZED (0).

View File

@ -66,8 +66,8 @@ export function makeErrorDetails(
details: Record<string, unknown>,
): OperationErrorDetails {
return {
talerErrorCode: ec,
talerErrorHint: `Error: ${TalerErrorCode[ec]}`,
code: ec,
hint: `Error: ${TalerErrorCode[ec]}`,
details: details,
message,
};

View File

@ -262,6 +262,7 @@ async function gatherWithdrawalPending(
source: wsr.source,
withdrawalGroupId: wsr.withdrawalGroupId,
lastError: wsr.lastError,
retryInfo: wsr.retryInfo,
});
});
}

View File

@ -165,6 +165,7 @@ export async function getTransactions(
TransactionType.Withdrawal,
wsr.withdrawalGroupId,
),
...(wsr.lastError ? { error: wsr.lastError} : {}),
});
}
break;

View File

@ -59,6 +59,7 @@ import {
import { readSuccessResponseJsonOrThrow } from "../util/http";
import { URL } from "../util/url";
import { TalerErrorCode } from "../TalerErrorCode";
import { encodeCrock } from "../crypto/talerCrypto";
const logger = new Logger("withdraw.ts");
@ -558,9 +559,6 @@ async function incrementWithdrawalRetry(
if (!wsr) {
return;
}
if (!wsr.retryInfo) {
return;
}
wsr.retryInfo.retryCounter++;
updateRetryInfoTimeout(wsr.retryInfo);
wsr.lastError = err;
@ -647,12 +645,13 @@ async function processWithdrawGroupImpl(
let numFinished = 0;
let finishedForFirstTime = false;
let errorsPerCoin: Record<number, OperationErrorDetails> = {};
await ws.db.runWithWriteTransaction(
[Stores.coins, Stores.withdrawalGroups, Stores.reserves, Stores.planchets],
async (tx) => {
const ws = await tx.get(Stores.withdrawalGroups, withdrawalGroupId);
if (!ws) {
const wg = await tx.get(Stores.withdrawalGroups, withdrawalGroupId);
if (!wg) {
return;
}
@ -662,22 +661,29 @@ async function processWithdrawGroupImpl(
if (x.withdrawalDone) {
numFinished++;
}
if (x.lastError) {
errorsPerCoin[x.coinIdx] = x.lastError;
}
});
if (ws.timestampFinish === undefined && numFinished == numTotalCoins) {
logger.trace(`now withdrawn ${numFinished} of ${numTotalCoins} coins`);
if (wg.timestampFinish === undefined && numFinished === numTotalCoins) {
finishedForFirstTime = true;
ws.timestampFinish = getTimestampNow();
ws.lastError = undefined;
ws.retryInfo = initRetryInfo(false);
wg.timestampFinish = getTimestampNow();
wg.lastError = undefined;
wg.retryInfo = initRetryInfo(false);
}
await tx.put(Stores.withdrawalGroups, ws);
await tx.put(Stores.withdrawalGroups, wg);
},
);
if (numFinished != numTotalCoins) {
// FIXME: aggregate individual problems into the big error message here.
throw Error(
throw OperationFailedError.fromCode(
TalerErrorCode.WALLET_WITHDRAWAL_GROUP_INCOMPLETE,
`withdrawal did not finish (${numFinished} / ${numTotalCoins} coins withdrawn)`,
{
errorsPerCoin,
},
);
}

View File

@ -210,6 +210,7 @@ export interface PendingWithdrawOperation {
type: PendingOperationType.Withdraw;
source: WithdrawalSource;
lastError: OperationErrorDetails | undefined;
retryInfo: RetryInfo;
withdrawalGroupId: string;
numCoinsWithdrawn: number;
numCoinsTotal: number;
@ -229,6 +230,12 @@ export interface PendingOperationInfoCommon {
* as opposed to some regular scheduled operation or a permanent failure.
*/
givesLifeness: boolean;
/**
* Retry info, not available on all pending operations.
* If it is available, it must have the same name.
*/
retryInfo?: RetryInfo;
}
/**

View File

@ -42,6 +42,7 @@ import {
codecForList,
codecForAny,
} from "../util/codec";
import { OperationErrorDetails } from "./walletTypes";
export interface TransactionsRequest {
/**
@ -63,24 +64,6 @@ export interface TransactionsResponse {
transactions: Transaction[];
}
export interface TransactionError {
/**
* TALER_EC_* unique error code.
* The action(s) offered and message displayed on the transaction item depend on this code.
*/
ec: number;
/**
* English-only error hint, if available.
*/
hint?: string;
/**
* Error details specific to "ec", if applicable/available
*/
details?: any;
}
export interface TransactionCommon {
// opaque unique ID for the transaction, used as a starting point for paginating queries
// and for invoking actions on the transaction (e.g. deleting/hiding it from the history)
@ -103,7 +86,7 @@ export interface TransactionCommon {
// Amount added or removed from the wallet's balance (including all fees and other costs)
amountEffective: AmountString;
error?: TransactionError;
error?: OperationErrorDetails;
}
export type Transaction =

View File

@ -51,7 +51,6 @@ import {
buildCodecForUnion,
} from "../util/codec";
import { AmountString, codecForContractTerms, ContractTerms } from "./talerTypes";
import { TransactionError, OrderShortInfo, codecForOrderShortInfo } from "./transactions";
/**
* Response for the create reserve request to the wallet.
@ -215,7 +214,7 @@ export interface ConfirmPayResultDone {
export interface ConfirmPayResultPending {
type: ConfirmPayResultType.Pending;
lastError: TransactionError;
lastError: OperationErrorDetails;
}
export type ConfirmPayResult = ConfirmPayResultDone | ConfirmPayResultPending;

View File

@ -299,10 +299,15 @@ export class Wallet {
* liveness left. The wallet will be in a stopped state when this function
* returns without resolving to an exception.
*/
public async runUntilDone(): Promise<void> {
public async runUntilDone(
req: {
maxRetries?: number;
} = {},
): Promise<void> {
let done = false;
const p = new Promise((resolve, reject) => {
// Run this asynchronously
// Monitor for conditions that means we're done or we
// should quit with an error (due to exceeded retries).
this.addNotificationListener((n) => {
if (done) {
return;
@ -315,7 +320,29 @@ export class Wallet {
logger.trace("no liveness-giving operations left");
resolve();
}
const maxRetries = req.maxRetries;
if (!maxRetries) {
return;
}
this.getPendingOperations({ onlyDue: false })
.then((pending) => {
for (const p of pending.pendingOperations) {
if (p.retryInfo && p.retryInfo.retryCounter > maxRetries) {
console.warn(
`stopping, as ${maxRetries} retries are exceeded in an operation of type ${p.type}`,
);
this.stop();
done = true;
resolve();
}
}
})
.catch((e) => {
logger.error(e);
reject(e);
});
});
// Run this asynchronously
this.runRetryLoop().catch((e) => {
logger.error("exception in wallet retry loop");
reject(e);
@ -324,16 +351,6 @@ export class Wallet {
await p;
}
/**
* Run the wallet until there are no more pending operations that give
* liveness left. The wallet will be in a stopped state when this function
* returns without resolving to an exception.
*/
public async runUntilDoneAndStop(): Promise<void> {
await this.runUntilDone();
logger.trace("stopping after liveness-giving operations done");
this.stop();
}
/**
* Process pending operations and wait for scheduled operations in
@ -392,7 +409,7 @@ export class Wallet {
if (e instanceof OperationFailedAndReportedError) {
logger.warn("operation processed resulted in reported error");
} else {
console.error("Uncaught exception", e);
logger.error("Uncaught exception", e);
this.ws.notify({
type: NotificationType.InternalError,
message: "uncaught exception",
@ -902,10 +919,13 @@ export class Wallet {
return getTransactions(this.ws, request);
}
async withdrawTestBalance(
req: WithdrawTestBalanceRequest,
): Promise<void> {
await withdrawTestBalance(this.ws, req.amount, req.bankBaseUrl, req.exchangeBaseUrl);
async withdrawTestBalance(req: WithdrawTestBalanceRequest): Promise<void> {
await withdrawTestBalance(
this.ws,
req.amount,
req.bankBaseUrl,
req.exchangeBaseUrl,
);
}
async runIntegrationtest(args: IntegrationTestArgs): Promise<void> {
@ -940,12 +960,12 @@ export class Wallet {
case "runIntegrationTest": {
const req = codecForIntegrationTestArgs().decode(payload);
await this.runIntegrationtest(req);
return {}
return {};
}
case "testPay": {
const req = codecForTestPayArgs().decode(payload);
await this.testPay(req);
return {}
return {};
}
case "getTransactions": {
const req = codecForTransactionsRequest().decode(payload);
@ -988,10 +1008,7 @@ export class Wallet {
}
case "setExchangeTosAccepted": {
const req = codecForAcceptExchangeTosRequest().decode(payload);
await this.acceptExchangeTermsOfService(
req.exchangeBaseUrl,
req.etag,
);
await this.acceptExchangeTermsOfService(req.exchangeBaseUrl, req.etag);
return {};
}
case "applyRefund": {