Skip to content

Commit 55ac642

Browse files
committed
Improve timeout handling and error recovery
- Enhanced Lightning Network error handling with specific timeout detection - Made pathfinding and bot handler timeouts configurable via environment variables - Implemented exponential backoff retry strategy for failed payments - Added timeout monitoring and structured logging for better debugging - Enhanced PendingPayment model with error tracking and retry scheduling Fixes 60-second timeout issues that were causing bot unresponsiveness.
1 parent 6ee5069 commit 55ac642

6 files changed

Lines changed: 144 additions & 13 deletions

File tree

.env-sample

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -61,6 +61,12 @@ LOG_LEVEL='debug'
6161
# Max routing fee that we want to pay to the network, 0.001 = 0.1%
6262
MAX_ROUTING_FEE=0.001
6363

64+
# Lightning Network pathfinding timeout in milliseconds (default: 60000 = 60 seconds)
65+
LN_PATHFINDING_TIMEOUT=60000
66+
67+
# Telegram bot handler timeout in milliseconds (default: 60000 = 60 seconds)
68+
BOT_HANDLER_TIMEOUT=60000
69+
6470
# Attempts to pay the invoice again when the payment failed
6571
PAYMENT_ATTEMPTS=2
6672

app.ts

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,9 @@ import { CommunityContext } from "./bot/modules/community/communityContext";
2525
mongoose.connection
2626
.once('open', async () => {
2727
logger.info('Connected to Mongo instance.');
28-
let options: Partial<Telegraf.Options<CommunityContext>> = { handlerTimeout: 60000 };
28+
// Use configurable bot handler timeout, default to 60 seconds
29+
const handlerTimeout = parseInt(process.env.BOT_HANDLER_TIMEOUT || '60000');
30+
let options: Partial<Telegraf.Options<CommunityContext>> = { handlerTimeout };
2931
if (process.env.SOCKS_PROXY_HOST) {
3032
const agent = new SocksProxyAgent(process.env.SOCKS_PROXY_HOST);
3133
options = {

jobs/pending_payments.ts

Lines changed: 48 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -14,12 +14,21 @@ export const attemptPendingPayments = async (bot: Telegraf<CommunityContext>): P
1414
attempts: { $lt: process.env.PAYMENT_ATTEMPTS },
1515
is_invoice_expired: false,
1616
community_id: null,
17+
next_retry: { $lte: new Date() },
1718
});
1819
for (const pending of pendingPayments) {
1920
const order = await Order.findOne({ _id: pending.order_id });
2021
try {
2122
if (order === null) throw Error("Order was not found in DB");
2223
pending.attempts++;
24+
25+
// Calculate exponential backoff delay
26+
const baseDelay = 5 * 60 * 1000; // 5 minutes
27+
const exponentialDelay = baseDelay * Math.pow(2, pending.attempts - 1);
28+
const maxDelay = 60 * 60 * 1000; // 1 hour max
29+
const nextRetryDelay = Math.min(exponentialDelay, maxDelay);
30+
pending.next_retry = new Date(Date.now() + nextRetryDelay);
31+
2332
if (order.status === 'SUCCESS') {
2433
pending.paid = true;
2534
await pending.save();
@@ -85,9 +94,25 @@ export const attemptPendingPayments = async (bot: Telegraf<CommunityContext>): P
8594
);
8695
await messages.rateUserMessage(bot, buyerUser, order, i18nCtx);
8796
} else {
97+
// Enhanced error handling for different payment failure types
98+
if (payment && typeof payment === 'object' && 'error' in payment) {
99+
pending.last_error = payment.error as string;
100+
101+
if (payment.error === 'TIMEOUT') {
102+
logger.warn(`Payment timeout for order ${order._id}, attempt ${pending.attempts}`);
103+
} else if (payment.error === 'ROUTING_FAILED') {
104+
logger.warn(`Routing failed for order ${order._id}, attempt ${pending.attempts}`);
105+
} else {
106+
logger.error(`Payment failed for order ${order._id}, attempt ${pending.attempts}, error: ${payment.error}`);
107+
}
108+
} else {
109+
pending.last_error = 'PAYMENT_FAILED';
110+
logger.error(`Payment failed for order ${order._id}, attempt ${pending.attempts}`);
111+
}
112+
88113
if (
89114
process.env.PAYMENT_ATTEMPTS !== undefined &&
90-
pending.attempts === parseInt(process.env.PAYMENT_ATTEMPTS)
115+
pending.attempts >= parseInt(process.env.PAYMENT_ATTEMPTS)
91116
) {
92117
order.paid_hold_buyer_invoice_updated = false;
93118
await messages.toBuyerPendingPaymentFailedMessage(
@@ -124,11 +149,19 @@ export const attemptCommunitiesPendingPayments = async (bot: Telegraf<CommunityC
124149
attempts: { $lt: process.env.PAYMENT_ATTEMPTS },
125150
is_invoice_expired: false,
126151
community_id: { $ne: null },
152+
next_retry: { $lte: new Date() },
127153
});
128154

129155
for (const pending of pendingPayments) {
130156
try {
131157
pending.attempts++;
158+
159+
// Calculate exponential backoff delay for community payments
160+
const baseDelay = 5 * 60 * 1000; // 5 minutes
161+
const exponentialDelay = baseDelay * Math.pow(2, pending.attempts - 1);
162+
const maxDelay = 60 * 60 * 1000; // 1 hour max
163+
const nextRetryDelay = Math.min(exponentialDelay, maxDelay);
164+
pending.next_retry = new Date(Date.now() + nextRetryDelay);
132165

133166
// We check if this new payment is on flight
134167
const isPending: boolean = await isPendingPayment(pending.payment_request);
@@ -174,9 +207,22 @@ export const attemptCommunitiesPendingPayments = async (bot: Telegraf<CommunityC
174207
})
175208
);
176209
} else {
210+
// Enhanced error handling for community payments
211+
if (payment && typeof payment === 'object' && 'error' in payment) {
212+
pending.last_error = payment.error as string;
213+
logger.error(
214+
`Community ${community.id}: Withdraw failed after ${pending.attempts} attempts, amount ${pending.amount} sats, error: ${payment.error}`
215+
);
216+
} else {
217+
pending.last_error = 'PAYMENT_FAILED';
218+
logger.error(
219+
`Community ${community.id}: Withdraw failed after ${pending.attempts} attempts, amount ${pending.amount} sats`
220+
);
221+
}
222+
177223
if (
178224
process.env.PAYMENT_ATTEMPTS !== undefined &&
179-
pending.attempts === parseInt(process.env.PAYMENT_ATTEMPTS)
225+
pending.attempts >= parseInt(process.env.PAYMENT_ATTEMPTS)
180226
) {
181227
await bot.telegram.sendMessage(
182228
user.tg_id,
@@ -185,9 +231,6 @@ export const attemptCommunitiesPendingPayments = async (bot: Telegraf<CommunityC
185231
})
186232
);
187233
}
188-
logger.error(
189-
`Community ${community.id}: Withdraw failed after ${pending.attempts} attempts, amount ${pending.amount} sats`
190-
);
191234
}
192235
} catch (error) {
193236
logger.error(`attemptCommunitiesPendingPayments catch error: ${error}`);

ln/pay_request.ts

Lines changed: 57 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@ import { User, PendingPayment } from '../models';
88
import lnd from './connect';
99
import { handleReputationItems, getUserI18nContext } from '../util';
1010
import * as messages from '../bot/messages';
11-
import { logger } from '../logger';
11+
import { logger, logTimeout, logOperationDuration } from '../logger';
1212
import * as OrderEvents from '../bot/modules/events/orders';
1313
import { IOrder } from '../models/order';
1414
import { HasTelegram } from '../bot/start';
@@ -24,6 +24,9 @@ interface PayViaPaymentRequestParams {
2424
}
2525

2626
const payRequest = async ({ request, amount }: { request: string, amount: number }) => {
27+
const startTime = Date.now();
28+
const operationName = 'payRequest';
29+
2730
try {
2831
const invoice = parsePaymentRequest({ request });
2932
if (!invoice) return false;
@@ -36,10 +39,13 @@ const payRequest = async ({ request, amount }: { request: string, amount: number
3639
// We need to set a max fee amount
3740
const maxFee = amount * parseFloat(maxRoutingFee);
3841

42+
// Use configurable pathfinding timeout, default to 60 seconds
43+
const pathfindingTimeout = parseInt(process.env.LN_PATHFINDING_TIMEOUT || '60000');
44+
3945
const params : PayViaPaymentRequestParams = {
4046
lnd,
4147
request,
42-
pathfinding_timeout: 60000,
48+
pathfinding_timeout: pathfindingTimeout,
4349
};
4450
// If the invoice doesn't have amount we add it to the params
4551
if (!invoice.tokens) params.tokens = amount;
@@ -51,12 +57,36 @@ const payRequest = async ({ request, amount }: { request: string, amount: number
5157
// Delete all routing reputations to clear pathfinding memory
5258
await deleteForwardingReputations({ lnd });
5359

60+
logger.info(`Starting payment for ${amount} sats with ${pathfindingTimeout}ms timeout`);
5461
const payment = await payViaPaymentRequest(params);
55-
62+
63+
logOperationDuration(operationName, startTime, true);
5664
return payment;
57-
} catch (error) {
58-
logger.error(`payRequest: ${error}`);
59-
return false;
65+
} catch (error: any) {
66+
const errorMessage = error.toString();
67+
const pathfindingTimeout = parseInt(process.env.LN_PATHFINDING_TIMEOUT || '60000');
68+
69+
logOperationDuration(operationName, startTime, false);
70+
71+
// Enhanced error handling for different timeout scenarios
72+
if (errorMessage.includes('TimeoutError') || errorMessage.includes('timed out')) {
73+
logTimeout('payRequest', pathfindingTimeout, error);
74+
logger.error(`payRequest timeout after ${pathfindingTimeout}ms: ${errorMessage}`);
75+
return { error: 'TIMEOUT', message: errorMessage };
76+
}
77+
78+
if (errorMessage.includes('UnknownPaymentHash') || errorMessage.includes('PaymentPathfindingFailedToFindPossibleRoute')) {
79+
logger.error(`payRequest routing failed: ${errorMessage}`);
80+
return { error: 'ROUTING_FAILED', message: errorMessage };
81+
}
82+
83+
if (errorMessage.includes('InsufficientBalance')) {
84+
logger.error(`payRequest insufficient balance: ${errorMessage}`);
85+
return { error: 'INSUFFICIENT_BALANCE', message: errorMessage };
86+
}
87+
88+
logger.error(`payRequest unexpected error: ${errorMessage}`);
89+
return { error: 'UNKNOWN', message: errorMessage };
6090
}
6191
};
6292

@@ -104,14 +134,34 @@ const payToBuyer = async (bot: HasTelegram, order: IOrder) => {
104134
);
105135
await messages.rateUserMessage(bot, buyerUser, order, i18nCtx);
106136
} else {
107-
await messages.invoicePaymentFailedMessage(bot, buyerUser, i18nCtx);
137+
// Handle different types of payment failures
138+
if (payment && typeof payment === 'object' && 'error' in payment) {
139+
const errorType = payment.error as string;
140+
141+
if (errorType === 'TIMEOUT') {
142+
logger.warn(`Payment timeout for order ${order._id}, will retry later`);
143+
await messages.invoicePaymentFailedMessage(bot, buyerUser, i18nCtx);
144+
} else if (errorType === 'ROUTING_FAILED') {
145+
logger.warn(`Routing failed for order ${order._id}, will retry with cleared reputation`);
146+
await messages.invoicePaymentFailedMessage(bot, buyerUser, i18nCtx);
147+
} else {
148+
logger.error(`Payment failed for order ${order._id} with error: ${errorType}`);
149+
await messages.invoicePaymentFailedMessage(bot, buyerUser, i18nCtx);
150+
}
151+
} else {
152+
await messages.invoicePaymentFailedMessage(bot, buyerUser, i18nCtx);
153+
}
154+
155+
// Create pending payment for retry
108156
const pp = new PendingPayment({
109157
amount: order.amount,
110158
payment_request: order.buyer_invoice,
111159
user_id: buyerUser._id,
112160
description: order.description,
113161
hash: order.hash,
114162
order_id: order._id,
163+
attempts: 1,
164+
last_error: payment && typeof payment === 'object' && 'error' in payment ? payment.error as string : 'UNKNOWN',
115165
});
116166
await pp.save();
117167
}

logger.ts

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,5 +23,31 @@ const logger = winston.createLogger({
2323
exitOnError: false,
2424
});
2525

26+
// Enhanced timeout monitoring utilities
27+
export const logTimeout = (operation: string, timeout: number, error?: any) => {
28+
const logData = {
29+
operation,
30+
timeout_ms: timeout,
31+
timestamp: new Date().toISOString(),
32+
error: error?.toString() || 'Unknown timeout error'
33+
};
34+
logger.error(`TIMEOUT_MONITOR: ${JSON.stringify(logData)}`);
35+
};
36+
37+
export const logOperationDuration = (operation: string, startTime: number, success: boolean = true) => {
38+
const duration = Date.now() - startTime;
39+
const logData = {
40+
operation,
41+
duration_ms: duration,
42+
success,
43+
timestamp: new Date().toISOString()
44+
};
45+
46+
if (duration > 30000) { // Log slow operations (>30s)
47+
logger.warn(`SLOW_OPERATION: ${JSON.stringify(logData)}`);
48+
} else {
49+
logger.info(`OPERATION_DURATION: ${JSON.stringify(logData)}`);
50+
}
51+
};
2652

2753
export { logger };

models/pending_payment.ts

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,8 @@ export interface IPendingPayment extends Document {
1313
user_id: string;
1414
order_id: string;
1515
community_id: string;
16+
last_error: string;
17+
next_retry: Date;
1618
}
1719

1820

@@ -37,6 +39,8 @@ const PendingPaymentSchema = new Schema<IPendingPayment>({
3739
user_id: { type: String },
3840
order_id: { type: String },
3941
community_id: { type: String },
42+
last_error: { type: String, default: '' },
43+
next_retry: { type: Date, default: () => new Date(Date.now() + 5 * 60 * 1000) },
4044
});
4145

4246

0 commit comments

Comments
 (0)