nntp-proxy 0.5.1

NNTP proxy server with per-command backend multiplexing, caching, metrics, and TUI dashboard
Documentation
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636
637
638
639
640
641
642
643
644
645
646
647
648
649
650
651
652
653
654
655
656
//! CRITICAL TEST: Ensure cache is checked BEFORE adaptive prechecking
//!
//! This test exists because we had a bug FOUR TIMES where adaptive prechecking
//! ran before cache checks, causing:
//! - Massive backend queries for cached data
//! - 9KB/s throughput instead of instant cache hits
//! - Unnecessary backend load
//!
//! These tests verify the correct ordering:
//! 1. Extract message-ID
//! 2. Check cache FIRST
//! 3. If cache hit, return immediately (optionally spawn background recheck)
//! 4. If cache miss, run adaptive prechecking
//!
//! DO NOT DELETE THESE TESTS. DO NOT REFACTOR THEM AWAY.

use crate::test_helpers::{connect_and_read_greeting, spawn_proxy_with_config};
use nntp_proxy::config::{Cache, Config, RoutingMode, Server};
use nntp_proxy::types::Port;
use std::sync::Arc;
use std::sync::atomic::{AtomicU64, Ordering};
use std::time::Duration;
use tokio::io::{AsyncBufReadExt, AsyncRead, AsyncWriteExt, BufReader};
use tokio::net::{
    TcpListener,
    tcp::{OwnedReadHalf, OwnedWriteHalf},
};
use tokio::sync::Notify;
use tokio::time::timeout;

async fn read_multiline_response<R>(reader: &mut BufReader<R>) -> String
where
    R: AsyncRead + Unpin,
{
    let mut line = String::new();
    reader.read_line(&mut line).await.unwrap();
    assert!(line.starts_with("220"), "Should get 220 response: {line}");
    let status_line = line.clone();

    loop {
        line.clear();
        reader.read_line(&mut line).await.unwrap();
        if line.trim() == "." {
            break;
        }
    }

    status_line
}

async fn yield_background_work() {
    for _ in 0..128 {
        tokio::task::yield_now().await;
    }
}

/// Count how many times backends are queried
#[derive(Clone)]
struct BackendQueryCounter {
    count: Arc<AtomicU64>,
    updates: Arc<Notify>,
}

impl BackendQueryCounter {
    fn new() -> Self {
        Self {
            count: Arc::new(AtomicU64::new(0)),
            updates: Arc::new(Notify::new()),
        }
    }

    fn increment(&self) {
        self.count.fetch_add(1, Ordering::SeqCst);
        self.updates.notify_waiters();
    }

    fn get(&self) -> u64 {
        self.count.load(Ordering::SeqCst)
    }

    fn reset(&self) {
        self.count.store(0, Ordering::SeqCst);
    }

    async fn wait_for_at_least(&self, expected: u64, within: Duration) {
        timeout(within, async {
            loop {
                let notified = self.updates.notified();
                if self.get() >= expected {
                    return;
                }
                notified.await;
            }
        })
        .await
        .unwrap_or_else(|_| {
            panic!("Timed out waiting for backend query count to reach {expected}")
        });
    }

    async fn assert_stays_at_most(&self, max_allowed: u64, within: Duration) {
        assert!(
            self.get() <= max_allowed,
            "Backend query count already exceeded limit: {} > {}",
            self.get(),
            max_allowed
        );

        let result = timeout(within, async {
            loop {
                let notified = self.updates.notified();
                let current = self.get();
                assert!(
                    current <= max_allowed,
                    "Backend query count exceeded limit: {current} > {max_allowed}"
                );
                notified.await;
            }
        })
        .await;

        assert!(
            result.is_err(),
            "Backend query count kept changing while verifying limit <= {max_allowed}"
        );
    }
}

/// Spawn mock server that counts queries
fn spawn_counting_mock_server(
    listener: TcpListener,
    name: &str,
    counter: BackendQueryCounter,
    has_article: bool,
) -> tokio::task::AbortHandle {
    let name = name.to_string();
    let task = tokio::spawn(async move {
        loop {
            let (mut stream, _) = listener.accept().await.unwrap();
            let counter = counter.clone();
            let name = name.clone();

            tokio::spawn(async move {
                // Send greeting
                stream
                    .write_all(format!("200 {name} Ready\r\n").as_bytes())
                    .await
                    .ok();

                let mut reader = BufReader::new(stream);
                let mut line = String::new();

                loop {
                    line.clear();
                    if reader.read_line(&mut line).await.unwrap_or(0) == 0 {
                        break;
                    }

                    let command = line.trim();

                    // Count all STAT/HEAD/ARTICLE queries
                    if command.starts_with("STAT ")
                        || command.starts_with("HEAD ")
                        || command.starts_with("ARTICLE ")
                    {
                        counter.increment();
                    }

                    if command.starts_with("AUTHINFO USER") {
                        reader
                            .get_mut()
                            .write_all(b"381 Password required\r\n")
                            .await
                            .ok();
                    } else if command.starts_with("AUTHINFO PASS") {
                        reader.get_mut().write_all(b"281 Ok\r\n").await.ok();
                    } else if command.starts_with("STAT ") {
                        if has_article {
                            reader
                                .get_mut()
                                .write_all(b"223 0 <test@example.com>\r\n")
                                .await
                                .ok();
                        } else {
                            reader
                                .get_mut()
                                .write_all(b"430 No such article\r\n")
                                .await
                                .ok();
                        }
                    } else if command.starts_with("HEAD ") {
                        if has_article {
                            reader
                                .get_mut()
                                .write_all(
                                    b"221 0 <test@example.com>\r\nSubject: Test\r\n\r\n.\r\n",
                                )
                                .await
                                .ok();
                        } else {
                            reader
                                .get_mut()
                                .write_all(b"430 No such article\r\n")
                                .await
                                .ok();
                        }
                    } else if command.starts_with("ARTICLE ") {
                        if has_article {
                            reader
                                .get_mut()
                                .write_all(b"220 0 <test@example.com>\r\nSubject: Test\r\n\r\nBody\r\n.\r\n")
                                .await
                                .ok();
                        } else {
                            reader
                                .get_mut()
                                .write_all(b"430 No such article\r\n")
                                .await
                                .ok();
                        }
                    } else if command.starts_with("QUIT") {
                        reader.get_mut().write_all(b"205 Goodbye\r\n").await.ok();
                        break;
                    } else {
                        reader.get_mut().write_all(b"200 OK\r\n").await.ok();
                    }
                }
            });
        }
    });

    task.abort_handle()
}

async fn connect_test_client(config: Config) -> (BufReader<OwnedReadHalf>, OwnedWriteHalf) {
    let proxy_port = spawn_proxy_with_config(config, RoutingMode::PerCommand)
        .await
        .unwrap();
    let client = connect_and_read_greeting(proxy_port).await.unwrap();
    let (read_half, write_half) = client.into_split();
    (BufReader::new(read_half), write_half)
}

/// CRITICAL TEST: Cache check must happen BEFORE adaptive prechecking for STAT
///
/// Bug history:
/// 1st occurrence: Initial implementation had precheck before cache
/// 2nd occurrence: Refactoring moved cache check after precheck
/// 3rd occurrence: Code reorganization accidentally swapped order
/// 4th occurrence: (current) - precheck was before cache check
///
/// Expected behavior:
/// - First STAT: Cache miss, triggers precheck (1-2 backend queries)
/// - Second STAT: Cache hit, ZERO backend queries (instant response)
#[tokio::test]
async fn test_stat_cache_hit_zero_backend_queries() {
    let backend_listener = TcpListener::bind("127.0.0.1:0").await.unwrap();
    let backend_port = backend_listener.local_addr().unwrap().port();

    // Create counter to track backend queries
    let counter = BackendQueryCounter::new();

    // Spawn counting mock server (has article)
    let _mock = spawn_counting_mock_server(backend_listener, "TestBackend", counter.clone(), true);

    // Create proxy config with caching and adaptive precheck
    let config = Config {
        servers: vec![
            Server::builder("127.0.0.1", Port::try_new(backend_port).unwrap())
                .name("TestBackend")
                .build()
                .unwrap(),
        ],
        cache: Some(Cache {
            store_article_bodies: true,
            adaptive_precheck: true,
            ..Default::default()
        }),
        ..Default::default()
    };

    let (mut reader, mut write_half) = connect_test_client(config).await;
    let mut line = String::new();

    // Reset counter before test
    counter.reset();

    // FIRST STAT - Cache miss, will query backend
    write_half
        .write_all(b"STAT <test@example.com>\r\n")
        .await
        .unwrap();
    line.clear();
    reader.read_line(&mut line).await.unwrap();
    assert!(line.starts_with("223"), "Should get 223 response: {line}");

    counter.wait_for_at_least(1, Duration::from_secs(1)).await;

    let first_queries = counter.get();
    assert!(
        first_queries >= 1,
        "First STAT should query backend at least once, got {first_queries} queries"
    );

    // Reset counter
    counter.reset();

    // SECOND STAT - MUST hit cache with ZERO backend queries
    write_half
        .write_all(b"STAT <test@example.com>\r\n")
        .await
        .unwrap();
    line.clear();
    reader.read_line(&mut line).await.unwrap();
    assert!(line.starts_with("223"), "Should get 223 response: {line}");

    counter
        .assert_stays_at_most(1, Duration::from_millis(200))
        .await;

    let second_queries = counter.get();

    // CRITICAL ASSERTION: Cache hit MUST NOT query backend
    // Background recheck is allowed but should be minimal
    assert!(
        second_queries <= 1,
        "CRITICAL BUG: Cache hit triggered {second_queries} backend queries! Should be 0 (or 1 for background recheck). \
         This means cache check is happening AFTER adaptive prechecking."
    );

    // Clean up
    write_half.write_all(b"QUIT\r\n").await.unwrap();
}

/// CRITICAL TEST: HEAD command cache hits must not query backends
#[tokio::test]
async fn test_head_cache_hit_zero_backend_queries() {
    let backend_listener = TcpListener::bind("127.0.0.1:0").await.unwrap();
    let backend_port = backend_listener.local_addr().unwrap().port();

    let counter = BackendQueryCounter::new();
    let _mock = spawn_counting_mock_server(backend_listener, "TestBackend", counter.clone(), true);

    let config = Config {
        servers: vec![
            Server::builder("127.0.0.1", Port::try_new(backend_port).unwrap())
                .name("TestBackend")
                .build()
                .unwrap(),
        ],
        cache: Some(Cache {
            store_article_bodies: true,
            adaptive_precheck: true,
            ..Default::default()
        }),
        ..Default::default()
    };

    let (mut reader, mut write_half) = connect_test_client(config).await;
    let mut line = String::new();

    counter.reset();

    // First HEAD - cache miss
    write_half
        .write_all(b"HEAD <test@example.com>\r\n")
        .await
        .unwrap();
    line.clear();
    reader.read_line(&mut line).await.unwrap();
    assert!(line.starts_with("221"), "Should get 221 response: {line}");

    // Read multiline response
    loop {
        line.clear();
        reader.read_line(&mut line).await.unwrap();
        if line.trim() == "." {
            break;
        }
    }

    counter.wait_for_at_least(1, Duration::from_secs(1)).await;
    let first_queries = counter.get();
    assert!(first_queries >= 1, "First HEAD should query backend");

    counter.reset();

    // Second HEAD - MUST hit cache
    write_half
        .write_all(b"HEAD <test@example.com>\r\n")
        .await
        .unwrap();
    line.clear();
    reader.read_line(&mut line).await.unwrap();
    assert!(line.starts_with("221"), "Should get 221 response: {line}");

    // Read multiline response
    loop {
        line.clear();
        reader.read_line(&mut line).await.unwrap();
        if line.trim() == "." {
            break;
        }
    }

    counter
        .assert_stays_at_most(1, Duration::from_millis(200))
        .await;
    let second_queries = counter.get();

    assert!(
        second_queries <= 1,
        "CRITICAL BUG: HEAD cache hit triggered {second_queries} backend queries! Should be 0 (or 1 for background recheck)"
    );

    write_half.write_all(b"QUIT\r\n").await.unwrap();
}

/// CRITICAL TEST: ARTICLE command cache hits must not query backends
#[tokio::test]
async fn test_article_cache_hit_zero_backend_queries() {
    let backend_listener = TcpListener::bind("127.0.0.1:0").await.unwrap();
    let backend_port = backend_listener.local_addr().unwrap().port();

    let counter = BackendQueryCounter::new();
    let _mock = spawn_counting_mock_server(backend_listener, "TestBackend", counter.clone(), true);

    let config = Config {
        servers: vec![
            Server::builder("127.0.0.1", Port::try_new(backend_port).unwrap())
                .name("TestBackend")
                .build()
                .unwrap(),
        ],
        cache: Some(Cache {
            store_article_bodies: true,
            adaptive_precheck: true,
            ..Default::default()
        }),
        ..Default::default()
    };

    let (mut reader, mut write_half) = connect_test_client(config).await;

    counter.reset();

    // First ARTICLE - cache miss
    write_half
        .write_all(b"ARTICLE <test@example.com>\r\n")
        .await
        .unwrap();
    read_multiline_response(&mut reader).await;

    let first_queries = counter.get();
    assert_eq!(first_queries, 1, "First ARTICLE should query backend once");

    yield_background_work().await;
    counter.reset();

    // Second ARTICLE - MUST hit cache
    write_half
        .write_all(b"ARTICLE <test@example.com>\r\n")
        .await
        .unwrap();
    read_multiline_response(&mut reader).await;

    let second_queries = counter.get();

    assert_eq!(
        second_queries, 0,
        "CRITICAL BUG: ARTICLE cache hit triggered {second_queries} backend queries. \
         Cache hits must not pick or query a backend."
    );

    write_half.write_all(b"QUIT\r\n").await.unwrap();
}

/// CRITICAL TEST: Batched ARTICLE cache hits must not bypass cache/precheck preparation.
#[tokio::test]
async fn test_batched_article_cache_hits_zero_backend_queries() {
    let backend_listener = TcpListener::bind("127.0.0.1:0").await.unwrap();
    let backend_port = backend_listener.local_addr().unwrap().port();

    let counter = BackendQueryCounter::new();
    let _mock = spawn_counting_mock_server(backend_listener, "TestBackend", counter.clone(), true);

    let config = Config {
        servers: vec![
            Server::builder("127.0.0.1", Port::try_new(backend_port).unwrap())
                .name("TestBackend")
                .build()
                .unwrap(),
        ],
        cache: Some(Cache {
            store_article_bodies: true,
            adaptive_precheck: true,
            ..Default::default()
        }),
        ..Default::default()
    };

    let (mut reader, mut write_half) = connect_test_client(config).await;

    counter.reset();

    write_half
        .write_all(b"ARTICLE <test@example.com>\r\n")
        .await
        .unwrap();
    read_multiline_response(&mut reader).await;
    assert_eq!(counter.get(), 1, "First ARTICLE should query backend once");

    yield_background_work().await;
    counter.reset();

    write_half
        .write_all(b"ARTICLE <test@example.com>\r\nARTICLE <test@example.com>\r\n")
        .await
        .unwrap();
    read_multiline_response(&mut reader).await;
    read_multiline_response(&mut reader).await;

    let second_queries = counter.get();
    assert_eq!(
        second_queries, 0,
        "CRITICAL BUG: batched ARTICLE cache hits triggered {second_queries} backend queries. \
         Batched cache hits must not bypass cache/precheck preparation."
    );

    write_half.write_all(b"QUIT\r\n").await.unwrap();
}

/// Fake-backend test: without article payload caching, ARTICLE requests still go upstream.
#[tokio::test]
async fn test_article_without_payload_cache_queries_backend_each_time() {
    let backend_listener = TcpListener::bind("127.0.0.1:0").await.unwrap();
    let backend_port = backend_listener.local_addr().unwrap().port();

    let counter = BackendQueryCounter::new();
    let _mock = spawn_counting_mock_server(backend_listener, "TestBackend", counter.clone(), true);

    let config = Config {
        servers: vec![
            Server::builder("127.0.0.1", Port::try_new(backend_port).unwrap())
                .name("TestBackend")
                .build()
                .unwrap(),
        ],
        cache: Some(Cache {
            store_article_bodies: false,
            adaptive_precheck: false,
            ..Default::default()
        }),
        ..Default::default()
    };

    let (mut reader, mut write_half) = connect_test_client(config).await;
    let mut line = String::new();

    for expected_queries in 1..=2 {
        write_half
            .write_all(b"ARTICLE <no-payload-cache@example.com>\r\n")
            .await
            .unwrap();
        line.clear();
        reader.read_line(&mut line).await.unwrap();
        assert!(line.starts_with("220"), "Should get 220 response: {line}");

        loop {
            line.clear();
            reader.read_line(&mut line).await.unwrap();
            if line.trim() == "." {
                break;
            }
        }

        assert_eq!(
            counter.get(),
            expected_queries,
            "cache_articles=false should not serve ARTICLE payloads from cache"
        );
    }

    write_half.write_all(b"QUIT\r\n").await.unwrap();
}

/// CRITICAL TEST: Cached 430s must not trigger backend queries
#[tokio::test]
async fn test_cached_430_zero_backend_queries() {
    let backend_listener = TcpListener::bind("127.0.0.1:0").await.unwrap();
    let backend_port = backend_listener.local_addr().unwrap().port();

    let counter = BackendQueryCounter::new();
    // Server doesn't have article (returns 430)
    let _mock = spawn_counting_mock_server(backend_listener, "TestBackend", counter.clone(), false);

    let config = Config {
        servers: vec![
            Server::builder("127.0.0.1", Port::try_new(backend_port).unwrap())
                .name("TestBackend")
                .build()
                .unwrap(),
        ],
        cache: Some(Cache {
            store_article_bodies: true,
            adaptive_precheck: true,
            ..Default::default()
        }),
        ..Default::default()
    };

    let (mut reader, mut write_half) = connect_test_client(config).await;
    let mut line = String::new();

    counter.reset();

    // First STAT - cache miss, backend returns 430
    write_half
        .write_all(b"STAT <missing@example.com>\r\n")
        .await
        .unwrap();
    line.clear();
    reader.read_line(&mut line).await.unwrap();
    assert!(line.starts_with("430"), "Should get 430 response: {line}");

    counter.wait_for_at_least(1, Duration::from_secs(1)).await;
    let first_queries = counter.get();
    assert!(first_queries >= 1, "First query should hit backend");

    counter.reset();

    // Second STAT - MUST hit cache with ZERO queries (430 is cached)
    write_half
        .write_all(b"STAT <missing@example.com>\r\n")
        .await
        .unwrap();
    line.clear();
    reader.read_line(&mut line).await.unwrap();
    assert!(
        line.starts_with("430"),
        "Should still get 430 response: {line}"
    );

    counter
        .assert_stays_at_most(1, Duration::from_millis(200))
        .await;
    let second_queries = counter.get();

    assert!(
        second_queries <= 1,
        "CRITICAL BUG: Cached 430 triggered {second_queries} backend queries! Should be 0 (or 1 for background recheck). \
         430 responses MUST be cached and served instantly."
    );

    write_half.write_all(b"QUIT\r\n").await.unwrap();
}