Skip to content

Commit d2a9d56

Browse files
zeljkoXtirumerlacollins-w
authored
feat: Timeout handling and additional plugin pool improvements (#691)
* feat: Timeout handling and additional plugin pool improvements * chore: PR suggestions * chore: PR suggestions * fix: Modify rust transport error as infra error --------- Co-authored-by: tirumerla <tirumerla@gmail.com> Co-authored-by: collins-w <delanhype@gmail.com>
1 parent 46e29bc commit d2a9d56

15 files changed

Lines changed: 313 additions & 122 deletions

File tree

docs/plugins/index.mdx

Lines changed: 22 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -783,7 +783,6 @@ export PLUGIN_POOL_MAX_QUEUE_SIZE=10000
783783
| `PLUGIN_POOL_MAX_QUEUE_SIZE` | 4096 | `MAX_CONCURRENCY × 2` | Max queued requests |
784784
| `PLUGIN_POOL_QUEUE_SEND_TIMEOUT_MS` | 500 | Workload-based (500-1000ms) | Wait time when queue is full |
785785
| `PLUGIN_POOL_CONNECT_RETRIES` | 15 | - | Retry attempts when connecting |
786-
| `PLUGIN_POOL_REQUEST_TIMEOUT_SECS` | 30 | - | Timeout for pool requests |
787786
| `PLUGIN_POOL_WORKERS` | auto | CPU cores | Queue processing workers |
788787
| `PLUGIN_POOL_SOCKET_BACKLOG` | 2048 | `MAX_CONCURRENCY` | Socket connection backlog |
789788
| **Node.js Side** ||||
@@ -830,17 +829,30 @@ This ensures requests have sufficient time to queue during traffic spikes while
830829

831830
#### Timeout Alignment
832831

833-
<Callout type="warn">
834-
Timeouts must be aligned! If your plugin takes up to 120s, set the pool request timeout accordingly.
835-
</Callout>
832+
Plugin execution timeouts are derived from each plugin's `timeout` in `config.json` (default 300s). The only fixed internal timeout is for admin operations (`precompile`, `cache`, `invalidate`), which use 30s because they are expected to be fast.
836833

837-
```bash
838-
# In config.json: "timeout": 120
834+
For request handling, ensure the HTTP request timeout is large enough:
839835

840-
# Environment should match:
841-
export PLUGIN_POOL_REQUEST_TIMEOUT_SECS=120
836+
```json
837+
// 1. Plugin execution timeout (in config.json)
838+
{
839+
"plugins": [{
840+
"id": "my-plugin",
841+
"timeout": 120
842+
}]
843+
}
842844
```
843845

846+
```bash
847+
# 2. HTTP request timeout (must be strictly greater than plugin timeout)
848+
# The internal timeout hierarchy adds up to 4s of buffer, so allow at least 5s extra
849+
export REQUEST_TIMEOUT_SECONDS=125
850+
```
851+
852+
<Callout type="warn">
853+
`REQUEST_TIMEOUT_SECONDS` should be **at least 5 seconds greater** than your longest plugin `timeout` (e.g., plugin timeout of 120s → `REQUEST_TIMEOUT_SECONDS=125`). Internally, the system adds a 4s buffer across its timeout layers; if the HTTP timeout is shorter than plugin timeout + 5s, Actix may close the connection while cleanup is in progress, causing `write EPIPE` errors.
854+
</Callout>
855+
844856
#### Health & Recovery
845857

846858
Controls automatic health monitoring and recovery.
@@ -868,25 +880,24 @@ export PLUGIN_MAX_CONCURRENCY=1000
868880

869881
```bash
870882
export PLUGIN_MAX_CONCURRENCY=3000
871-
export PLUGIN_POOL_REQUEST_TIMEOUT_SECS=60
872883
```
873884

874885
#### Extreme Load (5000+ concurrent requests)
875886

876887
```bash
877888
export PLUGIN_MAX_CONCURRENCY=8000
878-
export PLUGIN_POOL_REQUEST_TIMEOUT_SECS=120
879889
export PLUGIN_POOL_CONNECT_RETRIES=20
880890
```
881891

882892
### Troubleshooting Common Errors
883893

884894
| Error | Cause | Solution |
885895
|-------|-------|----------|
896+
| `write EPIPE` / `Uncaught exception: Error: write EPIPE` | HTTP timeout while plugin still running | Set `REQUEST_TIMEOUT_SECONDS` at least 5s greater than your longest plugin `timeout` in config.json |
886897
| `Plugin execution queue is full` | More requests than queue can hold | Increase `PLUGIN_POOL_MAX_QUEUE_SIZE` and `PLUGIN_POOL_QUEUE_SEND_TIMEOUT_MS` |
887898
| `Connection limit reached` | Too many concurrent plugin connections | Increase `PLUGIN_SOCKET_MAX_CONCURRENT_CONNECTIONS` |
888899
| `Failed to connect to pool after N attempts` | Pool server overwhelmed | Increase `PLUGIN_POOL_CONNECT_RETRIES` and `PLUGIN_POOL_MAX_CONNECTIONS` |
889-
| `ScriptTimeout(N)` | Plugin execution exceeded timeout | Increase `timeout` in plugin config (config.json) |
900+
| `ScriptTimeout(N)` | Plugin execution exceeded timeout | Increase `timeout` in plugin config (config.json) and ensure `REQUEST_TIMEOUT_SECONDS` is at least 5s greater |
890901
| `All connection permits exhausted` | Connection pool at capacity | Increase `PLUGIN_POOL_MAX_CONNECTIONS` |
891902
| `FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory` | Worker heap too small | Increase `PLUGIN_WORKER_HEAP_MB` or reduce `PLUGIN_POOL_CONCURRENT_TASKS` |
892903
| `Pool server crashed and restarting` | Memory pressure or GC issues | Check logs for heap usage; reduce `PLUGIN_MAX_CONCURRENCY` or increase system RAM |

plugins/ARCHITECTURE.md

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -168,7 +168,6 @@ Per-request socket at `/tmp/relayer-shared-{uuid}.sock` for plugin API calls.
168168
|----------|---------|-------------|
169169
| `PLUGIN_POOL_WORKERS` | 0 (auto) | Rust queue worker threads |
170170
| `PLUGIN_POOL_CONNECT_RETRIES` | 15 | Connection retry attempts |
171-
| `PLUGIN_POOL_REQUEST_TIMEOUT_SECS` | 30 | Per-request timeout |
172171
| `PLUGIN_POOL_QUEUE_SEND_TIMEOUT_MS` | 500 | Queue wait timeout (auto-scales to 1000) |
173172
| `PLUGIN_POOL_IDLE_TIMEOUT` | 60000 | Worker idle timeout (ms) |
174173
| `PLUGIN_POOL_SOCKET_BACKLOG` | max(concurrency, 2048) | Socket backlog size |

plugins/lib/compiler.ts

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -22,8 +22,8 @@ const MAX_SOURCE_SIZE = 5 * 1024 * 1024;
2222
/** Maximum compiled code size (10MB) */
2323
const MAX_COMPILED_SIZE = 10 * 1024 * 1024;
2424

25-
/** Default compilation timeout (30 seconds) */
26-
const DEFAULT_COMPILE_TIMEOUT_MS = 30000;
25+
/** Compilation timeout (ms). Compilation is a fast operation similar to admin requests. */
26+
const DEFAULT_COMPILE_TIMEOUT_MS = 30000; // 30 seconds
2727

2828
/** Maximum concurrent compilations in batch mode */
2929
const MAX_CONCURRENT_COMPILATIONS = 10;

plugins/lib/constants.ts

Lines changed: 12 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -28,8 +28,16 @@ export const DEFAULT_POOL_IDLE_TIMEOUT_MS = 60000;
2828
/** Socket backlog for high concurrency */
2929
export const DEFAULT_POOL_SOCKET_BACKLOG = 2048;
3030

31-
/** Default execution timeout (ms) */
32-
export const DEFAULT_POOL_EXECUTION_TIMEOUT_MS = 30000;
31+
/**
32+
* Per-API-call socket timeout (ms). This is the timeout for individual
33+
* relayer API calls within a plugin (e.g., sendTransaction, getTransaction).
34+
* Short timeout since it's just a socket round-trip to the Rust relayer.
35+
*/
36+
export const SOCKET_REQUEST_TIMEOUT_MS = 30000; // 30 seconds
3337

34-
/** Default per-request timeout for socket communication (ms) */
35-
export const DEFAULT_SOCKET_REQUEST_TIMEOUT_MS = 30000;
38+
/**
39+
* Default plugin execution timeout (ms). Matches DEFAULT_PLUGIN_TIMEOUT_SECONDS
40+
* (300s) in Rust. In production, Rust sends the per-plugin timeout with each request,
41+
* so this is only a fallback for standalone testing.
42+
*/
43+
export const DEFAULT_PLUGIN_TIMEOUT_MS = 300000; // 5 minutes

plugins/lib/plugin.ts

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,7 @@ import {
4343
import { DefaultPluginKVStore } from './kv';
4444
import { LogInterceptor } from './logger';
4545
import type { PluginKVStore } from './kv';
46-
import { DEFAULT_SOCKET_REQUEST_TIMEOUT_MS } from './constants';
46+
import { SOCKET_REQUEST_TIMEOUT_MS } from './constants';
4747
import net from 'node:net';
4848
import { v4 as uuidv4 } from 'uuid';
4949

@@ -655,8 +655,8 @@ export class DefaultPluginAPI implements PluginAPI {
655655
// Set up timeout to prevent hanging forever
656656
timeoutId = setTimeout(() => {
657657
this.pending.delete(requestId);
658-
reject(new Error(`Socket request '${method}' timed out after ${DEFAULT_SOCKET_REQUEST_TIMEOUT_MS}ms`));
659-
}, DEFAULT_SOCKET_REQUEST_TIMEOUT_MS);
658+
reject(new Error(`Socket request '${method}' timed out after ${SOCKET_REQUEST_TIMEOUT_MS}ms`));
659+
}, SOCKET_REQUEST_TIMEOUT_MS);
660660

661661
// Wrap resolvers to clear timeout on completion
662662
this.pending.set(requestId, {

plugins/lib/pool-executor.ts

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -21,7 +21,7 @@ import {
2121
TransactionStatus,
2222
pluginError,
2323
} from '@openzeppelin/relayer-sdk';
24-
import { DEFAULT_SOCKET_REQUEST_TIMEOUT_MS } from './constants';
24+
import { SOCKET_REQUEST_TIMEOUT_MS } from './constants';
2525

2626
/**
2727
* Function Cache - Caches compiled plugin factory functions.
@@ -499,8 +499,8 @@ class PluginAPIImpl implements PluginAPI {
499499

500500
timeoutId = setTimeout(() => {
501501
this.pending.delete(requestId);
502-
reject(new Error(`Socket request '${method}' timed out after ${DEFAULT_SOCKET_REQUEST_TIMEOUT_MS}ms`));
503-
}, DEFAULT_SOCKET_REQUEST_TIMEOUT_MS);
502+
reject(new Error(`Socket request '${method}' timed out after ${SOCKET_REQUEST_TIMEOUT_MS}ms`));
503+
}, SOCKET_REQUEST_TIMEOUT_MS);
504504

505505
this.pending.set(requestId, {
506506
resolve: (value) => {

plugins/lib/pool-server.ts

Lines changed: 38 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -444,6 +444,23 @@ class PoolServer {
444444
const clientId = Math.random().toString(36).substring(7);
445445
debug(`[${clientId}] Client connected`);
446446

447+
/** Write to socket, silently handling EPIPE/ECONNRESET from disconnected clients */
448+
const safeWrite = (data: string): void => {
449+
if (!socket.writable) {
450+
debug(`[${clientId}] Socket no longer writable, discarding response`);
451+
return;
452+
}
453+
try {
454+
socket.write(data);
455+
} catch (err: any) {
456+
if (err.code === 'EPIPE' || err.code === 'ECONNRESET') {
457+
debug(`[${clientId}] Client disconnected during write (${err.code})`);
458+
} else {
459+
console.error(`[pool-server] [${clientId}] Write error:`, err);
460+
}
461+
}
462+
};
463+
447464
// Enable keep-alive to prevent connection drops
448465
socket.setKeepAlive(true, 30000); // 30 second keep-alive probe
449466
socket.setNoDelay(true); // Disable Nagle's algorithm for lower latency
@@ -473,12 +490,7 @@ class PoolServer {
473490
debug('Processing message type:', message.type);
474491
const response = await this.handleMessage(message);
475492
debug('Sending response for task:', response.taskId);
476-
// Check if socket is still writable before writing
477-
if (socket.writable) {
478-
socket.write(JSON.stringify(response) + '\n');
479-
} else {
480-
debug('Socket no longer writable, discarding response');
481-
}
493+
safeWrite(JSON.stringify(response) + '\n');
482494
} catch (err) {
483495
const error = err as Error;
484496
debug('Error handling message:', error);
@@ -490,9 +502,7 @@ class PoolServer {
490502
code: 'PARSE_ERROR',
491503
},
492504
};
493-
if (socket.writable) {
494-
socket.write(JSON.stringify(response) + '\n');
495-
}
505+
safeWrite(JSON.stringify(response) + '\n');
496506
}
497507
}
498508
})();
@@ -533,16 +543,15 @@ class PoolServer {
533543
success: false,
534544
error: { message: 'Internal queue processing error', code: 'QUEUE_ERROR' },
535545
};
536-
if (socket.writable) {
537-
socket.write(JSON.stringify(response) + '\n');
538-
}
546+
safeWrite(JSON.stringify(response) + '\n');
539547
});
540548
};
541549

542550
const errorHandler = (err: Error): void => {
543-
// Connection resets are normal during shutdown, don't log as errors
544-
if ((err as any).code === 'ECONNRESET') {
545-
debug(`[${clientId}] Connection reset`);
551+
// Connection resets and broken pipes are normal during shutdown or when clients disconnect
552+
const errorCode = (err as any).code;
553+
if (errorCode === 'ECONNRESET' || errorCode === 'EPIPE') {
554+
debug(`[${clientId}] Connection closed (${errorCode})`);
546555
} else {
547556
console.error(`[pool-server] [${clientId}] Socket error:`, err.message);
548557
}
@@ -1033,8 +1042,16 @@ async function main(): Promise<void> {
10331042

10341043
memoryMonitor.start();
10351044

1036-
// Handle uncaught exceptions to prevent silent crashes
1045+
// Handle uncaught exceptions to prevent silent crashes.
1046+
// EPIPE/ECONNRESET are expected when a plugin times out while an API call
1047+
// is in-flight — the Rust side closes the socket, and the plugin's pending
1048+
// write surfaces as an uncaught error. These should not kill the server.
10371049
process.on('uncaughtException', async (err) => {
1050+
const code = (err as any).code;
1051+
if (code === 'EPIPE' || code === 'ECONNRESET') {
1052+
debug(`[pool-server] Ignoring expected socket error in uncaughtException: ${code}`);
1053+
return;
1054+
}
10381055
console.error('[pool-server] Uncaught exception:', err);
10391056
try {
10401057
await server.stop();
@@ -1045,6 +1062,11 @@ async function main(): Promise<void> {
10451062
});
10461063

10471064
process.on('unhandledRejection', async (reason, promise) => {
1065+
const code = (reason as any)?.code;
1066+
if (code === 'EPIPE' || code === 'ECONNRESET') {
1067+
debug(`[pool-server] Ignoring expected socket error in unhandledRejection: ${code}`);
1068+
return;
1069+
}
10481070
console.error('[pool-server] Unhandled rejection at:', promise, 'reason:', reason);
10491071
try {
10501072
await server.stop();

plugins/lib/worker-pool.ts

Lines changed: 9 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -34,7 +34,7 @@ import type { PluginHeaders } from './plugin';
3434
import {
3535
DEFAULT_POOL_MIN_THREADS,
3636
DEFAULT_POOL_IDLE_TIMEOUT_MS,
37-
DEFAULT_POOL_EXECUTION_TIMEOUT_MS,
37+
DEFAULT_PLUGIN_TIMEOUT_MS,
3838
DEFAULT_POOL_MAX_THREADS_FLOOR,
3939
DEFAULT_POOL_CONCURRENT_TASKS_PER_WORKER,
4040
} from './constants';
@@ -51,8 +51,6 @@ export interface WorkerPoolOptions {
5151
concurrentTasksPerWorker?: number;
5252
/** Idle timeout before shutting down excess workers (ms) */
5353
idleTimeout?: number;
54-
/** Task-level timeout to prevent stuck workers (ms). Defaults to execution timeout + 5s buffer. */
55-
taskTimeout?: number;
5654
}
5755

5856
/**
@@ -104,17 +102,11 @@ export interface PluginExecutionResult {
104102
logs: LogEntry[];
105103
}
106104

107-
const DEFAULT_TIMEOUT = DEFAULT_POOL_EXECUTION_TIMEOUT_MS;
108-
109-
// Task timeout includes a 5s buffer over execution timeout for cleanup overhead
110-
const DEFAULT_TASK_TIMEOUT = DEFAULT_TIMEOUT + 5000;
111-
112105
const DEFAULT_OPTIONS: Required<WorkerPoolOptions> = {
113106
minThreads: DEFAULT_POOL_MIN_THREADS,
114107
maxThreads: Math.max(os.cpus().length, DEFAULT_POOL_MAX_THREADS_FLOOR),
115108
concurrentTasksPerWorker: DEFAULT_POOL_CONCURRENT_TASKS_PER_WORKER,
116109
idleTimeout: DEFAULT_POOL_IDLE_TIMEOUT_MS,
117-
taskTimeout: DEFAULT_TASK_TIMEOUT,
118110
};
119111

120112
/**
@@ -787,7 +779,7 @@ export class WorkerPoolManager {
787779
headers: request.headers,
788780
socketPath: request.socketPath,
789781
httpRequestId: request.httpRequestId,
790-
timeout: request.timeout ?? DEFAULT_TIMEOUT,
782+
timeout: request.timeout ?? DEFAULT_PLUGIN_TIMEOUT_MS,
791783
route: request.route,
792784
config: request.config,
793785
method: request.method,
@@ -797,9 +789,13 @@ export class WorkerPoolManager {
797789
// Track per-plugin execution (bounded to prevent memory leak)
798790
incrementBoundedMap(this.metrics.pluginExecutions, request.pluginId, MAX_METRICS_ENTRIES);
799791

800-
// Use task timeout to prevent permanently stuck workers
801-
// This is a safety net beyond the handler-level timeout in pool-executor
802-
const taskTimeout = this.options.taskTimeout;
792+
// Per-request timeout + 2s buffer as worker-pool safety net.
793+
// Derived from the actual plugin timeout so every layer in the hierarchy
794+
// uses the same base value:
795+
// 1. Handler (pool-executor.ts): T — structured TIMEOUT response
796+
// 2. Worker-pool safety net (here): T + 2s — catches stuck workers
797+
// 3. Rust backstop (pool_executor): T + 4s — catches hung Node.js process
798+
const taskTimeout = (request.timeout ?? DEFAULT_PLUGIN_TIMEOUT_MS) + 2000;
803799
let timeoutId: NodeJS.Timeout | undefined;
804800

805801
try {

src/constants/plugins.rs

Lines changed: 11 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,17 @@
1616
/// Override in config.json per-plugin: `"timeout": 60`
1717
pub const DEFAULT_PLUGIN_TIMEOUT_SECONDS: u64 = 300; // 5 minutes
1818

19+
/// Extra seconds added to the Rust-side timeout so both Node.js timeout layers
20+
/// fire first. The timeout hierarchy for a plugin with timeout T is:
21+
/// 1. Handler (pool-executor.ts): T — structured TIMEOUT response
22+
/// 2. Worker-pool safety net: T + 2s — catches stuck workers
23+
/// 3. Rust backstop (this buffer): T + 4s — catches hung Node.js process
24+
pub const PLUGIN_TIMEOUT_BUFFER_SECONDS: u64 = 4;
25+
26+
/// Timeout for admin pool requests (precompile, cache, invalidate) in seconds.
27+
/// These are fast operations that don't need the full plugin timeout.
28+
pub const ADMIN_REQUEST_TIMEOUT_SECS: u64 = 30;
29+
1930
// =============================================================================
2031
// Plugin Pool Server Configuration
2132
// These constants are the source of truth. The TypeScript pool-server.ts and
@@ -61,14 +72,6 @@ pub const DEFAULT_POOL_IDLE_TIMEOUT_MS: u64 = 60000; // 60 seconds
6172
/// Env: PLUGIN_POOL_SOCKET_BACKLOG (internal, rarely needs tuning)
6273
pub const DEFAULT_POOL_SOCKET_BACKLOG: u32 = 2048;
6374

64-
/// Plugin execution timeout within the pool (milliseconds).
65-
/// Internal constant - use per-plugin `timeout` in config.json instead.
66-
pub const DEFAULT_POOL_EXECUTION_TIMEOUT_MS: u64 = 30000; // 30 seconds
67-
68-
/// Timeout for individual pool requests (seconds).
69-
/// Env: PLUGIN_POOL_REQUEST_TIMEOUT_SECS
70-
pub const DEFAULT_POOL_REQUEST_TIMEOUT_SECS: u64 = 30;
71-
7275
/// Maximum queued requests before rejection.
7376
/// Env: PLUGIN_POOL_MAX_QUEUE_SIZE
7477
/// Increase for high concurrency (3000+ VUs).

src/domain/transaction/stellar/prepare/fee_bump.rs

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -527,10 +527,12 @@ mod signed_xdr_tests {
527527

528528
// Verify it's a fee-bump envelope
529529
if let Ok(envelope) = envelope_result {
530-
assert!(
531-
matches!(envelope, TransactionEnvelope::TxFeeBump(_)),
532-
"Should be a fee-bump envelope"
533-
);
530+
match envelope {
531+
TransactionEnvelope::TxFeeBump(fee_bump) => {
532+
assert_eq!(fee_bump.tx.fee, 2_000_000);
533+
}
534+
_ => panic!("Should be a fee-bump envelope"),
535+
}
534536
}
535537
} else {
536538
panic!("Expected Stellar transaction data");

0 commit comments

Comments
 (0)