slightly more sane logging

This commit is contained in:
Florian Dold 2019-08-26 01:39:13 +02:00
parent c367669d3b
commit e2b7441e73
No known key found for this signature in database
GPG Key ID: D2E4F00F29D02A4B
2 changed files with 63 additions and 76 deletions

View File

@ -24,7 +24,6 @@ export class NodeEmscriptenLoader {
} else { } else {
// We're in a normal node environment // We're in a normal node environment
const binaryPath = __dirname + "/../../../emscripten/taler-emscripten-lib.wasm"; const binaryPath = __dirname + "/../../../emscripten/taler-emscripten-lib.wasm";
console.log("reading from", binaryPath);
const wasmBinary = new Uint8Array(fs.readFileSync(binaryPath)); const wasmBinary = new Uint8Array(fs.readFileSync(binaryPath));
return wasmBinary; return wasmBinary;
} }

View File

@ -183,7 +183,7 @@ export function getTotalRefreshCost(
...withdrawDenoms.map(d => d.value), ...withdrawDenoms.map(d => d.value),
).amount; ).amount;
const totalCost = Amounts.sub(amountLeft, resultingAmount).amount; const totalCost = Amounts.sub(amountLeft, resultingAmount).amount;
console.log( Wallet.enableTracing && console.log(
"total refresh cost for", "total refresh cost for",
amountToPretty(amountLeft), amountToPretty(amountLeft),
"is", "is",
@ -242,19 +242,20 @@ export function selectPayCoins(
) >= 0; ) >= 0;
const isBelowFee = Amounts.cmp(accDepositFee, depositFeeLimit) <= 0; const isBelowFee = Amounts.cmp(accDepositFee, depositFeeLimit) <= 0;
console.log("candidate coin selection", { Wallet.enableTracing &&
coversAmount, console.log("candidate coin selection", {
isBelowFee, coversAmount,
accDepositFee, isBelowFee,
accAmount, accDepositFee,
paymentAmount, accAmount,
}); paymentAmount,
});
if ((coversAmount && isBelowFee) || coversAmountWithFee) { if ((coversAmount && isBelowFee) || coversAmountWithFee) {
const depositFeeToCover = Amounts.sub(accDepositFee, depositFeeLimit) const depositFeeToCover = Amounts.sub(accDepositFee, depositFeeLimit)
.amount; .amount;
leftAmount = Amounts.sub(leftAmount, depositFeeToCover).amount; leftAmount = Amounts.sub(leftAmount, depositFeeToCover).amount;
console.log("deposit fee to cover", amountToPretty(depositFeeToCover)); Wallet.enableTracing && console.log("deposit fee to cover", amountToPretty(depositFeeToCover));
let totalFees: AmountJson = Amounts.getZero(currency); let totalFees: AmountJson = Amounts.getZero(currency);
if (coversAmountWithFee && !isBelowFee) { if (coversAmountWithFee && !isBelowFee) {
@ -408,8 +409,6 @@ export class Wallet {
} }
async updateExchanges(): Promise<void> { async updateExchanges(): Promise<void> {
console.log("updating exchanges");
const exchangesUrls = await this.q() const exchangesUrls = await this.q()
.iter(Stores.exchanges) .iter(Stores.exchanges)
.map(e => e.baseUrl) .map(e => e.baseUrl)
@ -432,7 +431,8 @@ export class Wallet {
this.q() this.q()
.iter(Stores.reserves) .iter(Stores.reserves)
.forEach(reserve => { .forEach(reserve => {
Wallet.enableTracing && console.log("resuming reserve", reserve.reserve_pub); Wallet.enableTracing &&
console.log("resuming reserve", reserve.reserve_pub);
this.processReserve(reserve.reserve_pub); this.processReserve(reserve.reserve_pub);
}); });
@ -460,7 +460,8 @@ export class Wallet {
.iter(Stores.coins) .iter(Stores.coins)
.forEach((c: CoinRecord) => { .forEach((c: CoinRecord) => {
if (c.status === CoinStatus.Dirty) { if (c.status === CoinStatus.Dirty) {
Wallet.enableTracing && console.log("resuming pending refresh for coin", c); Wallet.enableTracing &&
console.log("resuming pending refresh for coin", c);
this.refresh(c.coinPub); this.refresh(c.coinPub);
} }
}); });
@ -509,9 +510,7 @@ export class Wallet {
} }
if (denom.value.currency !== currency) { if (denom.value.currency !== currency) {
console.warn( console.warn(
`same pubkey for different currencies at exchange ${ `same pubkey for different currencies at exchange ${exchange.baseUrl}`,
exchange.baseUrl
}`,
); );
continue; continue;
} }
@ -619,9 +618,7 @@ export class Wallet {
} }
if (denom.value.currency !== currency) { if (denom.value.currency !== currency) {
console.warn( console.warn(
`same pubkey for different currencies at exchange ${ `same pubkey for different currencies at exchange ${exchange.baseUrl}`,
exchange.baseUrl
}`,
); );
continue; continue;
} }
@ -727,11 +724,8 @@ export class Wallet {
let proposalId: number; let proposalId: number;
let checkResult: CheckPayResult; let checkResult: CheckPayResult;
try { try {
console.log("downloading proposal");
proposalId = await this.downloadProposal(url, downloadSessionId); proposalId = await this.downloadProposal(url, downloadSessionId);
console.log("calling checkPay");
checkResult = await this.checkPay(proposalId); checkResult = await this.checkPay(proposalId);
console.log("checkPay result", checkResult);
} catch (e) { } catch (e) {
return { return {
status: "error", status: "error",
@ -775,14 +769,11 @@ export class Wallet {
* downloaded in the context of a session ID. * downloaded in the context of a session ID.
*/ */
async downloadProposal(url: string, sessionId?: string): Promise<number> { async downloadProposal(url: string, sessionId?: string): Promise<number> {
console.log("downloading proposal from", url);
console.log("context session id is", sessionId);
const oldProposal = await this.q().getIndexed( const oldProposal = await this.q().getIndexed(
Stores.proposals.urlIndex, Stores.proposals.urlIndex,
url, url,
); );
if (oldProposal) { if (oldProposal) {
console.log("old proposal exists:", oldProposal);
return oldProposal.id!; return oldProposal.id!;
} }
@ -922,9 +913,10 @@ export class Wallet {
proposalId: number, proposalId: number,
sessionIdOverride: string | undefined, sessionIdOverride: string | undefined,
): Promise<ConfirmPayResult> { ): Promise<ConfirmPayResult> {
console.log( Wallet.enableTracing &&
`executing confirmPay with proposalId ${proposalId} and sessionIdOverride ${sessionIdOverride}`, console.log(
); `executing confirmPay with proposalId ${proposalId} and sessionIdOverride ${sessionIdOverride}`,
);
const proposal: ProposalDownloadRecord | undefined = await this.q().get( const proposal: ProposalDownloadRecord | undefined = await this.q().get(
Stores.proposals, Stores.proposals,
proposalId, proposalId,
@ -965,7 +957,7 @@ export class Wallet {
wireMethod: proposal.contractTerms.wire_method, wireMethod: proposal.contractTerms.wire_method,
}); });
console.log("coin selection result", res); Wallet.enableTracing && console.log("coin selection result", res);
if (!res) { if (!res) {
// Should not happen, since checkPay should be called first // Should not happen, since checkPay should be called first
@ -1037,9 +1029,6 @@ export class Wallet {
* look faster to the user. * look faster to the user.
*/ */
async checkPay(proposalId: number): Promise<CheckPayResult> { async checkPay(proposalId: number): Promise<CheckPayResult> {
console.log("doing checkPay for proposalId", proposalId)
const proposal = await this.q().get(Stores.proposals, proposalId); const proposal = await this.q().get(Stores.proposals, proposalId);
if (!proposal) { if (!proposal) {
@ -1052,7 +1041,7 @@ export class Wallet {
proposal.contractTermsHash, proposal.contractTermsHash,
); );
if (purchase) { if (purchase) {
console.log("got purchase", purchase) Wallet.enableTracing && console.log("got purchase", purchase);
return { status: "paid" }; return { status: "paid" };
} }
@ -1087,8 +1076,6 @@ export class Wallet {
return { status: "insufficient-balance" }; return { status: "insufficient-balance" };
} }
console.log("checkPay: payment possible!");
// Only create speculative signature if we don't already have one for this proposal // Only create speculative signature if we don't already have one for this proposal
if ( if (
!this.speculativePayData || !this.speculativePayData ||
@ -1107,7 +1094,8 @@ export class Wallet {
proposal, proposal,
proposalId, proposalId,
}; };
console.log("created speculative pay data for payment"); Wallet.enableTracing &&
console.log("created speculative pay data for payment");
} }
return { status: "payment-possible", coinSelection: res }; return { status: "payment-possible", coinSelection: res };
@ -1120,8 +1108,6 @@ export class Wallet {
async queryPaymentByFulfillmentUrl( async queryPaymentByFulfillmentUrl(
url: string, url: string,
): Promise<PurchaseRecord | undefined> { ): Promise<PurchaseRecord | undefined> {
console.log("query for payment", url);
const t = await this.q().getIndexed( const t = await this.q().getIndexed(
Stores.purchases.fulfillmentUrlIndex, Stores.purchases.fulfillmentUrlIndex,
url, url,
@ -1131,7 +1117,6 @@ export class Wallet {
console.log("query for payment failed"); console.log("query for payment failed");
return undefined; return undefined;
} }
console.log("query for payment succeeded:", t);
return t; return t;
} }
@ -1164,9 +1149,10 @@ export class Wallet {
2 * retryDelayMs + retryDelayMs * Math.random(), 2 * retryDelayMs + retryDelayMs * Math.random(),
3000 * 60, 3000 * 60,
); );
console.warn( Wallet.enableTracing &&
`Failed to deplete reserve, trying again in ${retryDelayMs} ms`, console.warn(
); `Failed to deplete reserve, trying again in ${retryDelayMs} ms`,
);
Wallet.enableTracing && console.info("Cause for retry was:", e); Wallet.enableTracing && console.info("Cause for retry was:", e);
this.timerGroup.after(retryDelayMs, () => this.timerGroup.after(retryDelayMs, () =>
processReserveInternal(nextDelay), processReserveInternal(nextDelay),
@ -1426,7 +1412,6 @@ export class Wallet {
console.error("Unable to confirm reserve, not found in DB"); console.error("Unable to confirm reserve, not found in DB");
return; return;
} }
console.log("reserve confirmed");
reserve.timestamp_confirmed = now; reserve.timestamp_confirmed = now;
await this.q() await this.q()
.put(Stores.reserves, reserve) .put(Stores.reserves, reserve)
@ -1479,7 +1464,7 @@ export class Wallet {
* the depleted timestamp. * the depleted timestamp.
*/ */
private async depleteReserve(reserve: ReserveRecord): Promise<void> { private async depleteReserve(reserve: ReserveRecord): Promise<void> {
console.log("depleting reserve"); Wallet.enableTracing && console.log("depleting reserve");
if (!reserve.current_amount) { if (!reserve.current_amount) {
throw Error("can't withdraw when amount is unknown"); throw Error("can't withdraw when amount is unknown");
} }
@ -1901,7 +1886,7 @@ export class Wallet {
const q = this.q(); const q = this.q();
resultSuspendedCoins.map((c: CoinRecord) => { resultSuspendedCoins.map((c: CoinRecord) => {
console.log("suspending coin", c); Wallet.enableTracing && console.log("suspending coin", c);
c.suspended = true; c.suspended = true;
q.put(Stores.coins, c); q.put(Stores.coins, c);
this.badge.showNotification(); this.badge.showNotification();
@ -1939,15 +1924,15 @@ export class Wallet {
lastUsedTime: 0, lastUsedTime: 0,
masterPublicKey: exchangeKeysJson.master_public_key, masterPublicKey: exchangeKeysJson.master_public_key,
}; };
console.log("making fresh exchange"); Wallet.enableTracing && console.log("making fresh exchange");
} else { } else {
if (updateTimeSec < r.lastUpdateTime) { if (updateTimeSec < r.lastUpdateTime) {
console.log("outdated /keys, not updating"); Wallet.enableTracing && console.log("outdated /keys, not updating");
return r; return r;
} }
exchangeInfo = r; exchangeInfo = r;
exchangeInfo.lastUpdateTime = updateTimeSec; exchangeInfo.lastUpdateTime = updateTimeSec;
console.log("updating old exchange"); Wallet.enableTracing && console.log("updating old exchange");
} }
const updatedExchangeInfo = await this.updateExchangeInfo( const updatedExchangeInfo = await this.updateExchangeInfo(
@ -2024,7 +2009,7 @@ export class Wallet {
if (!denom) { if (!denom) {
continue; continue;
} }
console.log(`cashing back denom`, denom); Wallet.enableTracing && console.log(`cashing back denom`, denom);
const coins = await this.q() const coins = await this.q()
.iterIndex(Stores.coins.denomPubIndex, denom.denomPub) .iterIndex(Stores.coins.denomPubIndex, denom.denomPub)
.toArray(); .toArray();
@ -2275,15 +2260,16 @@ export class Wallet {
availableDenoms, availableDenoms,
); );
console.log("refreshing coin", coin); Wallet.enableTracing && console.log("refreshing coin", coin);
console.log("refreshing into", newCoinDenoms); Wallet.enableTracing && console.log("refreshing into", newCoinDenoms);
if (newCoinDenoms.length === 0) { if (newCoinDenoms.length === 0) {
console.log( Wallet.enableTracing &&
`not refreshing, available amount ${amountToPretty( console.log(
availableAmount, `not refreshing, available amount ${amountToPretty(
)} too small`, availableAmount,
); )} too small`,
);
coin.status = CoinStatus.Useless; coin.status = CoinStatus.Useless;
await this.q().put(Stores.coins, coin); await this.q().put(Stores.coins, coin);
this.notifier.notify(); this.notifier.notify();
@ -2333,7 +2319,8 @@ export class Wallet {
.iter(Stores.refresh) .iter(Stores.refresh)
.toArray(); .toArray();
for (const session of oldRefreshSessions) { for (const session of oldRefreshSessions) {
Wallet.enableTracing && console.log("got old refresh session for", oldCoinPub, session); Wallet.enableTracing &&
console.log("got old refresh session for", oldCoinPub, session);
this.continueRefreshSession(session); this.continueRefreshSession(session);
} }
const coin = await this.q().get(Stores.coins, oldCoinPub); const coin = await this.q().get(Stores.coins, oldCoinPub);
@ -2350,7 +2337,7 @@ export class Wallet {
const refreshSession = await this.createRefreshSession(oldCoinPub); const refreshSession = await this.createRefreshSession(oldCoinPub);
if (!refreshSession) { if (!refreshSession) {
// refreshing not necessary // refreshing not necessary
console.log("not refreshing", oldCoinPub); Wallet.enableTracing && console.log("not refreshing", oldCoinPub);
return; return;
} }
this.continueRefreshSession(refreshSession); this.continueRefreshSession(refreshSession);
@ -2401,10 +2388,10 @@ export class Wallet {
rc: refreshSession.hash, rc: refreshSession.hash,
value_with_fee: refreshSession.valueWithFee, value_with_fee: refreshSession.valueWithFee,
}; };
console.log("melt request:", meltReq); Wallet.enableTracing && console.log("melt request:", meltReq);
const resp = await this.http.postJson(reqUrl.href(), meltReq); const resp = await this.http.postJson(reqUrl.href(), meltReq);
console.log("melt response:", resp.responseJson); Wallet.enableTracing && console.log("melt response:", resp.responseJson);
if (resp.status !== 200) { if (resp.status !== 200) {
console.error(resp.responseJson); console.error(resp.responseJson);
@ -2474,21 +2461,22 @@ export class Wallet {
const reqUrl = new URI("refresh/reveal").absoluteTo( const reqUrl = new URI("refresh/reveal").absoluteTo(
refreshSession.exchangeBaseUrl, refreshSession.exchangeBaseUrl,
); );
console.log("reveal request:", req); Wallet.enableTracing && console.log("reveal request:", req);
const resp = await this.http.postJson(reqUrl.href(), req); const resp = await this.http.postJson(reqUrl.href(), req);
console.log("session:", refreshSession); Wallet.enableTracing && console.log("session:", refreshSession);
console.log("reveal response:", resp); Wallet.enableTracing && console.log("reveal response:", resp);
if (resp.status !== 200) { if (resp.status !== 200) {
console.log("error: /refresh/reveal returned status " + resp.status); console.error("error: /refresh/reveal returned status " + resp.status);
return; return;
} }
const respJson = resp.responseJson; const respJson = resp.responseJson;
if (!respJson.ev_sigs || !Array.isArray(respJson.ev_sigs)) { if (!respJson.ev_sigs || !Array.isArray(respJson.ev_sigs)) {
console.log("/refresh/reveal did not contain ev_sigs"); console.error("/refresh/reveal did not contain ev_sigs");
return;
} }
const exchange = await this.q().get<ExchangeRecord>( const exchange = await this.q().get<ExchangeRecord>(
@ -2684,7 +2672,7 @@ export class Wallet {
} }
async updateCurrency(currencyRecord: CurrencyRecord): Promise<void> { async updateCurrency(currencyRecord: CurrencyRecord): Promise<void> {
console.log("updating currency to", currencyRecord); Wallet.enableTracing && console.log("updating currency to", currencyRecord);
await this.q() await this.q()
.put(Stores.currencies, currencyRecord) .put(Stores.currencies, currencyRecord)
.finish(); .finish();
@ -2833,7 +2821,7 @@ export class Wallet {
Object.keys(x.feesForType).map(k => s.add(k)); Object.keys(x.feesForType).map(k => s.add(k));
}) })
.run(); .run();
console.log(m); Wallet.enableTracing && console.log(m);
const exchangeWireTypes: { [url: string]: string[] } = {}; const exchangeWireTypes: { [url: string]: string[] } = {};
Object.keys(m).map(e => { Object.keys(m).map(e => {
exchangeWireTypes[e] = Array.from(m[e]); exchangeWireTypes[e] = Array.from(m[e]);
@ -2858,9 +2846,9 @@ export class Wallet {
* Trigger paying coins back into the user's account. * Trigger paying coins back into the user's account.
*/ */
async returnCoins(req: ReturnCoinsRequest): Promise<void> { async returnCoins(req: ReturnCoinsRequest): Promise<void> {
console.log("got returnCoins request", req); Wallet.enableTracing && console.log("got returnCoins request", req);
const wireType = (req.senderWire as any).type; const wireType = (req.senderWire as any).type;
console.log("wireType", wireType); Wallet.enableTracing && console.log("wireType", wireType);
if (!wireType || typeof wireType !== "string") { if (!wireType || typeof wireType !== "string") {
console.error(`wire type must be a non-empty string, not ${wireType}`); console.error(`wire type must be a non-empty string, not ${wireType}`);
return; return;
@ -2871,9 +2859,9 @@ export class Wallet {
console.error(`Exchange ${req.exchange} not known to the wallet`); console.error(`Exchange ${req.exchange} not known to the wallet`);
return; return;
} }
console.log("selecting coins for return:", req); Wallet.enableTracing && console.log("selecting coins for return:", req);
const cds = await this.getCoinsForReturn(req.exchange, req.amount); const cds = await this.getCoinsForReturn(req.exchange, req.amount);
console.log(cds); Wallet.enableTracing && console.log(cds);
if (!cds) { if (!cds) {
throw Error("coin return impossible, can't select coins"); throw Error("coin return impossible, can't select coins");
@ -2917,7 +2905,7 @@ export class Wallet {
Amounts.parseOrThrow(contractTerms.amount), Amounts.parseOrThrow(contractTerms.amount),
); );
console.log("pci", payCoinInfo); Wallet.enableTracing && console.log("pci", payCoinInfo);
const coins = payCoinInfo.sigs.map(s => ({ coinPaySig: s })); const coins = payCoinInfo.sigs.map(s => ({ coinPaySig: s }));
@ -2962,7 +2950,7 @@ export class Wallet {
wire: coinsReturnRecord.wire, wire: coinsReturnRecord.wire,
wire_transfer_deadline: coinsReturnRecord.contractTerms.pay_deadline, wire_transfer_deadline: coinsReturnRecord.contractTerms.pay_deadline,
}; };
console.log("req", req); Wallet.enableTracing && console.log("req", req);
const reqUrl = new URI("deposit").absoluteTo(coinsReturnRecord.exchange); const reqUrl = new URI("deposit").absoluteTo(coinsReturnRecord.exchange);
const resp = await this.http.postJson(reqUrl.href(), req); const resp = await this.http.postJson(reqUrl.href(), req);
if (resp.status !== 200) { if (resp.status !== 200) {
@ -3052,12 +3040,12 @@ export class Wallet {
* that was involved in the refund. * that was involved in the refund.
*/ */
async acceptRefund(refundUrl: string): Promise<string> { async acceptRefund(refundUrl: string): Promise<string> {
console.log("processing refund"); Wallet.enableTracing && console.log("processing refund");
let resp; let resp;
try { try {
resp = await this.http.get(refundUrl); resp = await this.http.get(refundUrl);
} catch (e) { } catch (e) {
console.log("error downloading refund permission", e); console.error("error downloading refund permission", e);
throw e; throw e;
} }