netget/server/tftp/mod.rs
1//! TFTP server implementation
2pub mod actions;
3
4use crate::server::connection::ConnectionId;
5use anyhow::Result;
6use std::collections::HashMap;
7use std::net::SocketAddr;
8use std::sync::Arc;
9use tokio::net::UdpSocket;
10use tokio::sync::{mpsc, Mutex};
11use tracing::error;
12
13use crate::llm::action_helper::call_llm;
14use crate::llm::ollama_client::OllamaClient;
15use crate::logging::emit::Log;
16use crate::protocol::Event;
17use crate::server::TftpProtocol;
18use crate::state::app_state::AppState;
19use actions::{
20 TFTP_ACK_RECEIVED_EVENT, TFTP_DATA_BLOCK_EVENT, TFTP_READ_REQUEST_EVENT,
21 TFTP_WRITE_REQUEST_EVENT,
22};
23
24/// RFC 1350 opcodes. Named rather than spelled as literals at each comparison, because the
25/// read continuation used to test a packet's *length* where it meant to test its opcode.
26const OP_DATA: u16 = 3;
27const OP_ERROR: u16 = 5;
28
29/// How many consecutive `recv_from` failures on the main socket are tolerated before the
30/// accept loop gives up.
31///
32/// One error is routine on UDP: an ICMP port-unreachable provoked by a datagram we sent to a
33/// client that has gone away is delivered as an error on the *next* receive. A permanent one
34/// is not, and `continue`ing on it turns this loop into a busy-wait that also floods the
35/// unbounded status channel.
36const MAX_CONSECUTIVE_SOCKET_ERRORS: u32 = 64;
37
38/// Transfer ID (client address + transaction ID port)
39#[derive(Debug, Clone, Copy, Hash, PartialEq, Eq)]
40struct TransferId {
41 client_addr: SocketAddr,
42}
43
44impl TransferId {
45 fn new(client_addr: SocketAddr) -> Self {
46 Self { client_addr }
47 }
48}
49
50/// TFTP transfer operation type
51#[derive(Debug, Clone, Copy, PartialEq, Eq)]
52enum TftpOperation {
53 Read, // Server sends DATA, receives ACK
54 Write, // Server receives DATA, sends ACK
55}
56
57/// Transfer state
58#[allow(dead_code)]
59struct TftpTransfer {
60 transfer_id: TransferId,
61 operation: TftpOperation,
62 filename: String,
63 mode: String,
64 current_block: u16,
65 connection_id: ConnectionId,
66 server_socket: Arc<UdpSocket>, // Unique socket for this transfer (TID)
67}
68
69/// TFTP server that forwards requests to LLM
70pub struct TftpServer;
71
72impl TftpServer {
73 /// Spawn TFTP server with integrated LLM actions
74 pub async fn spawn_with_llm_actions(
75 listen_addr: SocketAddr,
76 llm_client: OllamaClient,
77 app_state: Arc<AppState>,
78 status_tx: mpsc::UnboundedSender<String>,
79 server_id: crate::state::ServerId,
80 ) -> Result<SocketAddr> {
81 // Main listening socket (port 69)
82 let main_socket = Arc::new(UdpSocket::bind(listen_addr).await?);
83 let local_addr = main_socket.local_addr()?;
84 Log::new(Some(&status_tx)).info(format!("TFTP server listening on {}", local_addr));
85
86 let protocol = Arc::new(TftpProtocol::new());
87
88 // Active transfers (keyed by TransferId)
89 let transfers: Arc<Mutex<HashMap<TransferId, TftpTransfer>>> =
90 Arc::new(Mutex::new(HashMap::new()));
91
92 // Spawn main request listener (handles RRQ and WRQ)
93 let main_socket_clone = main_socket.clone();
94 let llm_clone = llm_client.clone();
95 let state_clone = app_state.clone();
96 let status_clone = status_tx.clone();
97 let protocol_clone = protocol.clone();
98 let transfers_clone = transfers.clone();
99
100 let accept_handle = tokio::spawn(async move {
101 Self::handle_main_requests(
102 main_socket_clone,
103 llm_clone,
104 state_clone,
105 status_clone,
106 server_id,
107 protocol_clone,
108 transfers_clone,
109 )
110 .await;
111 });
112
113 app_state
114 .register_server_task(server_id, accept_handle)
115 .await;
116
117 Ok(local_addr)
118 }
119
120 /// Handle incoming requests on main socket (RRQ and WRQ)
121 async fn handle_main_requests(
122 main_socket: Arc<UdpSocket>,
123 llm_client: OllamaClient,
124 app_state: Arc<AppState>,
125 status_tx: mpsc::UnboundedSender<String>,
126 server_id: crate::state::ServerId,
127 protocol: Arc<TftpProtocol>,
128 transfers: Arc<Mutex<HashMap<TransferId, TftpTransfer>>>,
129 ) {
130 let mut buffer = vec![0u8; 516]; // Max TFTP packet (4 bytes header + 512 data)
131 let log = Log::new(Some(&status_tx));
132 let mut consecutive_errors: u32 = 0;
133
134 loop {
135 match main_socket.recv_from(&mut buffer).await {
136 Ok((n, peer_addr)) => {
137 consecutive_errors = 0;
138 let data = buffer[..n].to_vec();
139
140 // Summary + full payload FileOnly: the tftp_*_request event
141 // templates render the equivalent lines to the TUI.
142 log.debug(format!("TFTP received {} bytes from {}", n, peer_addr));
143 log.trace(format!("TFTP packet (hex): {}", hex::encode(&data)));
144
145 // Parse TFTP opcode
146 if data.len() < 2 {
147 log.debug("TFTP packet too short, ignoring");
148 continue;
149 }
150
151 let opcode = u16::from_be_bytes([data[0], data[1]]);
152
153 match opcode {
154 1 => {
155 // RRQ (Read Request)
156 let llm_clone = llm_client.clone();
157 let state_clone = app_state.clone();
158 let status_clone = status_tx.clone();
159 let protocol_clone = protocol.clone();
160 let transfers_clone = transfers.clone();
161
162 // Tracked, not detached: stop_server must abort this task too.
163 let task_owner = app_state.clone();
164 task_owner
165 .spawn_server_task(server_id, async move {
166 if let Err(e) = Self::handle_read_request(
167 data,
168 peer_addr,
169 llm_clone,
170 state_clone,
171 status_clone,
172 server_id,
173 protocol_clone,
174 transfers_clone,
175 )
176 .await
177 {
178 error!("TFTP RRQ handling error: {}", e);
179 }
180 })
181 .await;
182 }
183 2 => {
184 // WRQ (Write Request)
185 let llm_clone = llm_client.clone();
186 let state_clone = app_state.clone();
187 let status_clone = status_tx.clone();
188 let protocol_clone = protocol.clone();
189 let transfers_clone = transfers.clone();
190
191 // Tracked, not detached: stop_server must abort this task too.
192 let task_owner = app_state.clone();
193 task_owner
194 .spawn_server_task(server_id, async move {
195 if let Err(e) = Self::handle_write_request(
196 data,
197 peer_addr,
198 llm_clone,
199 state_clone,
200 status_clone,
201 server_id,
202 protocol_clone,
203 transfers_clone,
204 )
205 .await
206 {
207 error!("TFTP WRQ handling error: {}", e);
208 }
209 })
210 .await;
211 }
212 _ => {
213 log.debug(format!(
214 "TFTP unexpected opcode {} on main socket, ignoring",
215 opcode
216 ));
217 }
218 }
219 }
220 Err(e) => {
221 // A UDP socket reports transient per-datagram errors here — on Linux an
222 // ICMP port-unreachable from a client that has gone away surfaces as
223 // ECONNREFUSED on the *next* recv — so a single error must not stop the
224 // server. But `continue`ing on a permanent one (the socket closed under
225 // us) spins this loop at 100% CPU and floods the unbounded status
226 // channel, which is what it did. Tolerate a burst, then give up.
227 consecutive_errors += 1;
228 log.error(format!(
229 "TFTP main socket error ({consecutive_errors} in a row): {e}"
230 ));
231 if consecutive_errors >= MAX_CONSECUTIVE_SOCKET_ERRORS {
232 log.error(format!(
233 "TFTP main socket failed {MAX_CONSECUTIVE_SOCKET_ERRORS} times in a \
234 row; stopping the accept loop rather than spinning on it"
235 ));
236 return;
237 }
238 }
239 }
240 }
241 }
242
243 /// Handle RRQ (Read Request)
244 async fn handle_read_request(
245 data: Vec<u8>,
246 peer_addr: SocketAddr,
247 llm_client: OllamaClient,
248 app_state: Arc<AppState>,
249 status_tx: mpsc::UnboundedSender<String>,
250 server_id: crate::state::ServerId,
251 protocol: Arc<TftpProtocol>,
252 transfers: Arc<Mutex<HashMap<TransferId, TftpTransfer>>>,
253 ) -> Result<()> {
254 // Parse RRQ: opcode(2) filename(string) 0 mode(string) 0
255 let (filename, mode) = Self::parse_request(&data[2..])?;
256 let log = Log::new(Some(&status_tx));
257
258 log.debug(format!(
259 "TFTP RRQ: filename='{}' mode='{}' from {}",
260 filename, mode, peer_addr
261 ));
262
263 // Create unique socket for this transfer (transaction ID)
264 let transfer_socket = Arc::new(UdpSocket::bind("0.0.0.0:0").await?);
265 let tid_addr = transfer_socket.local_addr()?;
266
267 log.debug(format!("TFTP RRQ assigned TID {}", tid_addr.port()));
268
269 // Create connection entry
270 let connection_id = ConnectionId::new(app_state.get_next_unified_id().await);
271 use crate::state::server::{
272 ConnectionState as ServerConnectionState, ConnectionStatus, ProtocolConnectionInfo,
273 };
274 let now = crate::utils::clock::Instant::now();
275 let conn_state = ServerConnectionState {
276 id: connection_id,
277 remote_addr: peer_addr,
278 local_addr: tid_addr,
279 bytes_sent: 0,
280 bytes_received: data.len() as u64,
281 packets_sent: 0,
282 packets_received: 1,
283 last_activity: now,
284 status: ConnectionStatus::Active,
285 status_changed_at: now,
286 protocol_info: ProtocolConnectionInfo::new(serde_json::json!({
287 "operation": "read",
288 "filename": filename.clone(),
289 "current_block": 0,
290 "total_bytes": 0,
291 })),
292 };
293 app_state
294 .add_connection_to_server(server_id, conn_state)
295 .await;
296 let _ = status_tx.send("__UPDATE_UI__".to_string());
297
298 // Create transfer state
299 let transfer_id = TransferId::new(peer_addr);
300 let transfer = TftpTransfer {
301 transfer_id,
302 operation: TftpOperation::Read,
303 filename: filename.clone(),
304 mode: mode.clone(),
305 current_block: 0,
306 connection_id,
307 server_socket: transfer_socket.clone(),
308 };
309
310 transfers.lock().await.insert(transfer_id, transfer);
311
312 // Call LLM with read request event
313 let event = Event::new(
314 &TFTP_READ_REQUEST_EVENT,
315 serde_json::json!({
316 "filename": filename,
317 "mode": mode,
318 "client_addr": peer_addr.to_string(),
319 }),
320 );
321
322 log.debug(format!("TFTP calling LLM for RRQ: {}", filename));
323
324 match call_llm(
325 &llm_client,
326 &app_state,
327 server_id,
328 Some(connection_id),
329 &event,
330 protocol.as_ref(),
331 )
332 .await
333 {
334 Ok(execution_result) => {
335 // Display messages
336 for message in &execution_result.messages {
337 log.info(message);
338 }
339
340 log.debug(format!(
341 "TFTP parsed {} actions for RRQ",
342 execution_result.raw_actions.len()
343 ));
344
345 let decision = Self::classify_outcome(&execution_result);
346 Self::log_decision(&log, decision, "RRQ", peer_addr, &execution_result);
347
348 // Process protocol results (DATA or ERROR packets)
349 for protocol_result in execution_result.protocol_results {
350 match protocol_result {
351 crate::llm::actions::protocol_trait::ActionResult::Output(packet) => {
352 // Send packet from transfer socket to client
353 if let Err(e) = transfer_socket.send_to(&packet, peer_addr).await {
354 log.error(format!("TFTP failed to send DATA: {}", e));
355 continue;
356 }
357
358 // Update bytes sent
359 app_state
360 .update_connection_stats(
361 server_id,
362 connection_id,
363 None,
364 Some(packet.len() as u64),
365 None,
366 Some(1),
367 )
368 .await;
369
370 log.trace(format!(
371 "TFTP sent DATA packet (hex): {}",
372 hex::encode(&packet)
373 ));
374
375 // Check if this is DATA packet
376 if packet.len() >= 4 {
377 let opcode = u16::from_be_bytes([packet[0], packet[1]]);
378 if opcode == 3 {
379 // DATA
380 let block_num = u16::from_be_bytes([packet[2], packet[3]]);
381 let data_len = packet.len() - 4;
382
383 // Update transfer state
384 if let Some(transfer) =
385 transfers.lock().await.get_mut(&transfer_id)
386 {
387 transfer.current_block = block_num;
388 }
389
390 // Update connection info
391 app_state
392 .update_tftp_connection_block(
393 server_id,
394 connection_id,
395 block_num,
396 data_len,
397 )
398 .await;
399
400 log.debug(format!(
401 "TFTP sent DATA block {} ({} bytes)",
402 block_num, data_len
403 ));
404
405 // If final block (< 512 bytes data), spawn ACK listener
406 if data_len < 512 {
407 log.debug("TFTP final block sent, waiting for final ACK");
408
409 // Spawn listener for final ACK
410 let socket_clone = transfer_socket.clone();
411 let status_clone = status_tx.clone();
412 let state_clone = app_state.clone();
413 let transfers_clone = transfers.clone();
414
415 // Tracked, not detached: stop_server must abort this task too.
416 let task_owner = app_state.clone();
417 task_owner
418 .spawn_server_task(server_id, async move {
419 Self::wait_for_final_ack(
420 socket_clone,
421 peer_addr,
422 transfer_id,
423 block_num,
424 server_id,
425 connection_id,
426 state_clone,
427 status_clone,
428 transfers_clone,
429 )
430 .await;
431 })
432 .await;
433 } else {
434 // Spawn listener for ACK and continue transfer
435 let socket_clone = transfer_socket.clone();
436 let llm_clone = llm_client.clone();
437 let state_clone = app_state.clone();
438 let status_clone = status_tx.clone();
439 let protocol_clone = protocol.clone();
440 let transfers_clone = transfers.clone();
441
442 // Tracked, not detached: stop_server must abort this task too.
443 let task_owner = app_state.clone();
444 task_owner
445 .spawn_server_task(server_id, async move {
446 Self::continue_read_transfer(
447 socket_clone,
448 peer_addr,
449 transfer_id,
450 block_num,
451 llm_clone,
452 state_clone,
453 status_clone,
454 server_id,
455 connection_id,
456 protocol_clone,
457 transfers_clone,
458 )
459 .await;
460 })
461 .await;
462 }
463 } else if opcode == 5 {
464 // ERROR - transfer terminated
465 log.debug("TFTP sent ERROR, transfer terminated");
466 transfers.lock().await.remove(&transfer_id);
467 app_state
468 .close_connection_on_server(server_id, connection_id)
469 .await;
470 }
471 }
472 }
473 _ => {}
474 }
475 }
476 }
477 Err(e) => {
478 Self::fail_transfer_on_llm_error(
479 &transfer_socket,
480 peer_addr,
481 transfer_id,
482 "read request",
483 &e,
484 server_id,
485 connection_id,
486 &app_state,
487 &status_tx,
488 &transfers,
489 )
490 .await;
491 }
492 }
493
494 Ok(())
495 }
496
497 /// Continue read transfer by waiting for ACK and calling LLM for next block
498 fn continue_read_transfer(
499 socket: Arc<UdpSocket>,
500 peer_addr: SocketAddr,
501 transfer_id: TransferId,
502 expected_block: u16,
503 llm_client: OllamaClient,
504 app_state: Arc<AppState>,
505 status_tx: mpsc::UnboundedSender<String>,
506 server_id: crate::state::ServerId,
507 connection_id: ConnectionId,
508 protocol: Arc<TftpProtocol>,
509 transfers: Arc<Mutex<HashMap<TransferId, TftpTransfer>>>,
510 ) -> std::pin::Pin<Box<dyn std::future::Future<Output = ()> + Send>> {
511 Box::pin(async move {
512 let mut buffer = vec![0u8; 516];
513 let log = Log::new(Some(&status_tx));
514
515 // Wait for ACK with timeout
516 match tokio::time::timeout(
517 std::time::Duration::from_secs(5),
518 socket.recv_from(&mut buffer),
519 )
520 .await
521 {
522 Ok(Ok((n, _))) => {
523 let data = &buffer[..n];
524
525 if data.len() >= 4 {
526 let opcode = u16::from_be_bytes([data[0], data[1]]);
527 if opcode == 4 {
528 // ACK
529 let ack_block = u16::from_be_bytes([data[2], data[3]]);
530
531 log.debug(format!("TFTP received ACK for block {}", ack_block));
532
533 if ack_block == expected_block {
534 // Update connection
535 app_state
536 .update_connection_stats(
537 server_id,
538 connection_id,
539 Some(n as u64),
540 None,
541 Some(1),
542 None,
543 )
544 .await;
545
546 // Call LLM for next block
547 let event = Event::new(
548 &TFTP_ACK_RECEIVED_EVENT,
549 serde_json::json!({
550 "block_number": ack_block,
551 }),
552 );
553
554 match call_llm(
555 &llm_client,
556 &app_state,
557 server_id,
558 Some(connection_id),
559 &event,
560 protocol.as_ref(),
561 )
562 .await
563 {
564 Ok(execution_result) => {
565 let decision = Self::classify_outcome(&execution_result);
566 Self::log_decision(
567 &log,
568 decision,
569 "ACK continuation",
570 peer_addr,
571 &execution_result,
572 );
573
574 // Exactly one continuation may be spawned per answer.
575 // The model can legitimately return several actions,
576 // and spawning a reader per packet would put two or
577 // more tasks on the same socket racing for the next
578 // ACK.
579 let mut continued = false;
580 for protocol_result in execution_result.protocol_results {
581 if let crate::llm::actions::protocol_trait::ActionResult::Output(packet) = protocol_result {
582 if let Err(e) = socket.send_to(&packet, peer_addr).await {
583 log.error(format!(
584 "TFTP failed to send packet to {peer_addr}: {e}"
585 ));
586 continue;
587 }
588
589 app_state.update_connection_stats(server_id, connection_id, None, Some(packet.len() as u64), None, Some(1)).await;
590
591 if continued {
592 continue;
593 }
594
595 // Dispatch on the opcode, as the RRQ path does.
596 // This branch used to test only the length, so an
597 // ERROR packet — which is short — was taken for a
598 // final DATA block: the server waited five seconds
599 // for an ACK the client had no reason to send, and
600 // read the packet's *error code* as a block number.
601 // Aborting a transfer mid-flight therefore looked
602 // to the log like a completed one.
603 match Self::packet_opcode(&packet) {
604 Some(OP_DATA) => {
605 let block_num = u16::from_be_bytes([packet[2], packet[3]]);
606 let data_len = packet.len() - 4;
607 continued = true;
608
609 let socket_clone = socket.clone();
610 let state_clone = app_state.clone();
611 let status_clone = status_tx.clone();
612 let transfers_clone = transfers.clone();
613
614 if data_len < 512 {
615 log.debug("TFTP final block sent");
616 // Tracked, not detached: stop_server must abort this task too.
617 let task_owner = app_state.clone();
618 task_owner.spawn_server_task(server_id, async move {
619 Self::wait_for_final_ack(
620 socket_clone,
621 peer_addr,
622 transfer_id,
623 block_num,
624 server_id,
625 connection_id,
626 state_clone,
627 status_clone,
628 transfers_clone,
629 )
630 .await;
631 }).await;
632 } else {
633 let llm_clone = llm_client.clone();
634 let protocol_clone = protocol.clone();
635 // Tracked, not detached: stop_server must abort this task too.
636 let task_owner = app_state.clone();
637 task_owner.spawn_server_task(server_id, async move {
638 Self::continue_read_transfer(
639 socket_clone,
640 peer_addr,
641 transfer_id,
642 block_num,
643 llm_clone,
644 state_clone,
645 status_clone,
646 server_id,
647 connection_id,
648 protocol_clone,
649 transfers_clone,
650 )
651 .await;
652 }).await;
653 }
654 }
655 Some(OP_ERROR) => {
656 log.debug(
657 "TFTP sent ERROR mid-transfer, transfer terminated",
658 );
659 continued = true;
660 transfers.lock().await.remove(&transfer_id);
661 app_state
662 .close_connection_on_server(server_id, connection_id)
663 .await;
664 }
665 other => {
666 log.warn(format!(
667 "TFTP handler answered a read transfer with opcode \
668 {other:?}, which is neither DATA nor ERROR; the \
669 transfer cannot continue"
670 ));
671 }
672 }
673 }
674 }
675 }
676 Err(e) => {
677 // Mid-transfer failure: the client is waiting for
678 // the next DATA block, so it gets an ERROR packet
679 // instead of nothing.
680 Self::fail_transfer_on_llm_error(
681 &socket,
682 peer_addr,
683 transfer_id,
684 "read transfer",
685 &e,
686 server_id,
687 connection_id,
688 &app_state,
689 &status_tx,
690 &transfers,
691 )
692 .await;
693 }
694 }
695 }
696 }
697 }
698 }
699 Ok(Err(e)) => {
700 log.error(format!("TFTP socket error waiting for ACK: {}", e));
701 transfers.lock().await.remove(&transfer_id);
702 app_state
703 .close_connection_on_server(server_id, connection_id)
704 .await;
705 }
706 Err(_) => {
707 log.debug(format!(
708 "TFTP timeout waiting for ACK block {}",
709 expected_block
710 ));
711 transfers.lock().await.remove(&transfer_id);
712 app_state
713 .close_connection_on_server(server_id, connection_id)
714 .await;
715 }
716 }
717 })
718 }
719
720 /// Wait for final ACK and close transfer
721 async fn wait_for_final_ack(
722 socket: Arc<UdpSocket>,
723 _peer_addr: SocketAddr,
724 transfer_id: TransferId,
725 expected_block: u16,
726 server_id: crate::state::ServerId,
727 connection_id: ConnectionId,
728 app_state: Arc<AppState>,
729 status_tx: mpsc::UnboundedSender<String>,
730 transfers: Arc<Mutex<HashMap<TransferId, TftpTransfer>>>,
731 ) {
732 let mut buffer = vec![0u8; 516];
733 let log = Log::new(Some(&status_tx));
734
735 match tokio::time::timeout(
736 std::time::Duration::from_secs(5),
737 socket.recv_from(&mut buffer),
738 )
739 .await
740 {
741 Ok(Ok((n, _))) => {
742 let data = &buffer[..n];
743
744 if data.len() >= 4 {
745 let opcode = u16::from_be_bytes([data[0], data[1]]);
746 if opcode == 4 {
747 let ack_block = u16::from_be_bytes([data[2], data[3]]);
748
749 if ack_block == expected_block {
750 log.debug(format!(
751 "TFTP transfer complete (final ACK received for block {})",
752 ack_block
753 ));
754
755 app_state
756 .update_connection_stats(
757 server_id,
758 connection_id,
759 Some(n as u64),
760 None,
761 Some(1),
762 None,
763 )
764 .await;
765
766 transfers.lock().await.remove(&transfer_id);
767 app_state
768 .close_connection_on_server(server_id, connection_id)
769 .await;
770 }
771 }
772 }
773 }
774 _ => {
775 log.debug("TFTP timeout waiting for final ACK (transfer may have completed)");
776 transfers.lock().await.remove(&transfer_id);
777 app_state
778 .close_connection_on_server(server_id, connection_id)
779 .await;
780 }
781 }
782 }
783
784 /// Handle WRQ (Write Request)
785 async fn handle_write_request(
786 data: Vec<u8>,
787 peer_addr: SocketAddr,
788 llm_client: OllamaClient,
789 app_state: Arc<AppState>,
790 status_tx: mpsc::UnboundedSender<String>,
791 server_id: crate::state::ServerId,
792 protocol: Arc<TftpProtocol>,
793 transfers: Arc<Mutex<HashMap<TransferId, TftpTransfer>>>,
794 ) -> Result<()> {
795 // Parse WRQ
796 let (filename, mode) = Self::parse_request(&data[2..])?;
797 let log = Log::new(Some(&status_tx));
798
799 log.debug(format!(
800 "TFTP WRQ: filename='{}' mode='{}' from {}",
801 filename, mode, peer_addr
802 ));
803
804 // Create unique socket for this transfer
805 let transfer_socket = Arc::new(UdpSocket::bind("0.0.0.0:0").await?);
806 let tid_addr = transfer_socket.local_addr()?;
807
808 log.debug(format!("TFTP WRQ assigned TID {}", tid_addr.port()));
809
810 // Create connection entry
811 let connection_id = ConnectionId::new(app_state.get_next_unified_id().await);
812 use crate::state::server::{
813 ConnectionState as ServerConnectionState, ConnectionStatus, ProtocolConnectionInfo,
814 };
815 let now = crate::utils::clock::Instant::now();
816 let conn_state = ServerConnectionState {
817 id: connection_id,
818 remote_addr: peer_addr,
819 local_addr: tid_addr,
820 bytes_sent: 0,
821 bytes_received: data.len() as u64,
822 packets_sent: 0,
823 packets_received: 1,
824 last_activity: now,
825 status: ConnectionStatus::Active,
826 status_changed_at: now,
827 protocol_info: ProtocolConnectionInfo::new(serde_json::json!({
828 "operation": "write",
829 "filename": filename.clone(),
830 "current_block": 0,
831 "total_bytes": 0,
832 })),
833 };
834 app_state
835 .add_connection_to_server(server_id, conn_state)
836 .await;
837 let _ = status_tx.send("__UPDATE_UI__".to_string());
838
839 // Create transfer state
840 let transfer_id = TransferId::new(peer_addr);
841 let transfer = TftpTransfer {
842 transfer_id,
843 operation: TftpOperation::Write,
844 filename: filename.clone(),
845 mode: mode.clone(),
846 current_block: 0,
847 connection_id,
848 server_socket: transfer_socket.clone(),
849 };
850
851 transfers.lock().await.insert(transfer_id, transfer);
852
853 // Call LLM with write request event
854 let event = Event::new(
855 &TFTP_WRITE_REQUEST_EVENT,
856 serde_json::json!({
857 "filename": filename,
858 "mode": mode,
859 "client_addr": peer_addr.to_string(),
860 }),
861 );
862
863 log.debug(format!("TFTP calling LLM for WRQ: {}", filename));
864
865 match call_llm(
866 &llm_client,
867 &app_state,
868 server_id,
869 Some(connection_id),
870 &event,
871 protocol.as_ref(),
872 )
873 .await
874 {
875 Ok(execution_result) => {
876 // Display messages
877 for message in &execution_result.messages {
878 log.info(message);
879 }
880
881 let decision = Self::classify_outcome(&execution_result);
882 Self::log_decision(&log, decision, "WRQ", peer_addr, &execution_result);
883
884 // Process protocol results (should be ACK block 0 or ERROR)
885 for protocol_result in execution_result.protocol_results {
886 match protocol_result {
887 crate::llm::actions::protocol_trait::ActionResult::Output(packet) => {
888 // Send ACK block 0 or ERROR
889 if let Err(e) = transfer_socket.send_to(&packet, peer_addr).await {
890 log.error(format!("TFTP failed to send ACK: {}", e));
891 continue;
892 }
893
894 app_state
895 .update_connection_stats(
896 server_id,
897 connection_id,
898 None,
899 Some(packet.len() as u64),
900 None,
901 Some(1),
902 )
903 .await;
904
905 log.trace(format!("TFTP sent packet (hex): {}", hex::encode(&packet)));
906
907 // Check if ACK (opcode 4)
908 if packet.len() >= 4 {
909 let opcode = u16::from_be_bytes([packet[0], packet[1]]);
910 if opcode == 4 {
911 log.debug("TFTP sent ACK block 0, ready to receive");
912
913 // Spawn listener for incoming DATA blocks
914 let socket_clone = transfer_socket.clone();
915 let llm_clone = llm_client.clone();
916 let state_clone = app_state.clone();
917 let status_clone = status_tx.clone();
918 let protocol_clone = protocol.clone();
919 let transfers_clone = transfers.clone();
920
921 // Tracked, not detached: stop_server must abort this task too.
922 let task_owner = app_state.clone();
923 task_owner
924 .spawn_server_task(server_id, async move {
925 Self::receive_write_data(
926 socket_clone,
927 peer_addr,
928 transfer_id,
929 llm_clone,
930 state_clone,
931 status_clone,
932 server_id,
933 connection_id,
934 protocol_clone,
935 transfers_clone,
936 )
937 .await;
938 })
939 .await;
940 } else if opcode == 5 {
941 log.debug("TFTP sent ERROR, transfer denied");
942 transfers.lock().await.remove(&transfer_id);
943 app_state
944 .close_connection_on_server(server_id, connection_id)
945 .await;
946 }
947 }
948 }
949 _ => {}
950 }
951 }
952 }
953 Err(e) => {
954 Self::fail_transfer_on_llm_error(
955 &transfer_socket,
956 peer_addr,
957 transfer_id,
958 "write request",
959 &e,
960 server_id,
961 connection_id,
962 &app_state,
963 &status_tx,
964 &transfers,
965 )
966 .await;
967 }
968 }
969
970 Ok(())
971 }
972
973 /// Receive DATA blocks for write transfer
974 async fn receive_write_data(
975 socket: Arc<UdpSocket>,
976 peer_addr: SocketAddr,
977 transfer_id: TransferId,
978 llm_client: OllamaClient,
979 app_state: Arc<AppState>,
980 status_tx: mpsc::UnboundedSender<String>,
981 server_id: crate::state::ServerId,
982 connection_id: ConnectionId,
983 protocol: Arc<TftpProtocol>,
984 transfers: Arc<Mutex<HashMap<TransferId, TftpTransfer>>>,
985 ) {
986 let mut buffer = vec![0u8; 516];
987 let log = Log::new(Some(&status_tx));
988
989 loop {
990 match tokio::time::timeout(
991 std::time::Duration::from_secs(10),
992 socket.recv_from(&mut buffer),
993 )
994 .await
995 {
996 Ok(Ok((n, _))) => {
997 let data = buffer[..n].to_vec();
998
999 if data.len() < 4 {
1000 log.debug("TFTP received short packet, ignoring");
1001 continue;
1002 }
1003
1004 let opcode = u16::from_be_bytes([data[0], data[1]]);
1005 if opcode != 3 {
1006 log.debug(format!(
1007 "TFTP expected DATA (opcode 3), got opcode {}",
1008 opcode
1009 ));
1010 continue;
1011 }
1012
1013 let block_num = u16::from_be_bytes([data[2], data[3]]);
1014 let block_data = &data[4..];
1015
1016 // Summary FileOnly: the tftp_data_block event template renders
1017 // the equivalent line to the TUI.
1018 log.debug(format!(
1019 "TFTP received DATA block {} ({} bytes)",
1020 block_num,
1021 block_data.len()
1022 ));
1023
1024 app_state
1025 .update_connection_stats(
1026 server_id,
1027 connection_id,
1028 Some(n as u64),
1029 None,
1030 Some(1),
1031 None,
1032 )
1033 .await;
1034
1035 // Update transfer state
1036 if let Some(transfer) = transfers.lock().await.get_mut(&transfer_id) {
1037 transfer.current_block = block_num;
1038 }
1039
1040 app_state
1041 .update_tftp_connection_block(
1042 server_id,
1043 connection_id,
1044 block_num,
1045 block_data.len(),
1046 )
1047 .await;
1048
1049 // Call LLM with data block event
1050 let is_final = block_data.len() < 512;
1051 let event = Event::new(
1052 &TFTP_DATA_BLOCK_EVENT,
1053 serde_json::json!({
1054 "block_number": block_num,
1055 "data_hex": hex::encode(block_data),
1056 "data_length": block_data.len(),
1057 "is_final": is_final,
1058 }),
1059 );
1060
1061 match call_llm(
1062 &llm_client,
1063 &app_state,
1064 server_id,
1065 Some(connection_id),
1066 &event,
1067 protocol.as_ref(),
1068 )
1069 .await
1070 {
1071 Ok(execution_result) => {
1072 let decision = Self::classify_outcome(&execution_result);
1073 Self::log_decision(
1074 &log,
1075 decision,
1076 "DATA block",
1077 peer_addr,
1078 &execution_result,
1079 );
1080
1081 // Process ACK packets
1082 let mut aborted = false;
1083 for protocol_result in execution_result.protocol_results {
1084 if let crate::llm::actions::protocol_trait::ActionResult::Output(
1085 packet,
1086 ) = protocol_result
1087 {
1088 if let Err(e) = socket.send_to(&packet, peer_addr).await {
1089 log.error(format!(
1090 "TFTP failed to send packet to {peer_addr}: {e}"
1091 ));
1092 continue;
1093 }
1094
1095 app_state
1096 .update_connection_stats(
1097 server_id,
1098 connection_id,
1099 None,
1100 Some(packet.len() as u64),
1101 None,
1102 Some(1),
1103 )
1104 .await;
1105
1106 // The handler is allowed to abort an upload with
1107 // send_tftp_error. That used to be written to the wire and
1108 // then ignored: the loop went straight back to waiting for
1109 // the next DATA block, so a refused upload kept its socket
1110 // and its connection entry until the ten-second timeout.
1111 if Self::packet_opcode(&packet) == Some(OP_ERROR) {
1112 log.debug(
1113 "TFTP sent ERROR during upload, transfer terminated",
1114 );
1115 aborted = true;
1116 } else {
1117 log.debug(format!("TFTP sent ACK for block {}", block_num));
1118 }
1119 }
1120 }
1121
1122 if aborted {
1123 transfers.lock().await.remove(&transfer_id);
1124 app_state
1125 .close_connection_on_server(server_id, connection_id)
1126 .await;
1127 break;
1128 }
1129
1130 // If final block, close transfer
1131 if is_final {
1132 log.debug(format!(
1133 "TFTP write transfer complete (final block {} received)",
1134 block_num
1135 ));
1136 transfers.lock().await.remove(&transfer_id);
1137 app_state
1138 .close_connection_on_server(server_id, connection_id)
1139 .await;
1140 break;
1141 }
1142 }
1143 Err(e) => {
1144 // The client is waiting for an ACK for the block it just
1145 // sent; answer with ERROR rather than leaving it to retransmit
1146 // into a socket nobody is reading any more.
1147 Self::fail_transfer_on_llm_error(
1148 &socket,
1149 peer_addr,
1150 transfer_id,
1151 "write data block",
1152 &e,
1153 server_id,
1154 connection_id,
1155 &app_state,
1156 &status_tx,
1157 &transfers,
1158 )
1159 .await;
1160 break;
1161 }
1162 }
1163 }
1164 Ok(Err(e)) => {
1165 log.error(format!("TFTP socket error: {}", e));
1166 transfers.lock().await.remove(&transfer_id);
1167 app_state
1168 .close_connection_on_server(server_id, connection_id)
1169 .await;
1170 break;
1171 }
1172 Err(_) => {
1173 log.debug("TFTP timeout waiting for DATA");
1174 transfers.lock().await.remove(&transfer_id);
1175 app_state
1176 .close_connection_on_server(server_id, connection_id)
1177 .await;
1178 break;
1179 }
1180 }
1181 }
1182 }
1183
1184 /// What the handler produced for one TFTP event, as a stable `decision=` token.
1185 ///
1186 /// Must be computed **before** `protocol_results` is consumed, because every call site
1187 /// moves them into a `for` loop.
1188 ///
1189 /// TFTP is not one of the deliberately-silent protocols: it has a real ERROR frame
1190 /// (opcode 5), so a model that refuses says so on the wire and a model that says nothing
1191 /// reaches the client as **no packet at all**. Those two used to leave the same trace in
1192 /// the log, and the second one additionally leaves the transfer registered until the
1193 /// client's own retransmit timeout expires.
1194 fn classify_outcome(result: &crate::llm::ExecutionResult) -> &'static str {
1195 let outputs: Vec<Vec<u8>> = result
1196 .protocol_results
1197 .iter()
1198 .flat_map(|r| r.get_all_output())
1199 .collect();
1200
1201 if outputs
1202 .iter()
1203 .any(|p| Self::packet_opcode(p) == Some(OP_ERROR))
1204 {
1205 "model_reject"
1206 } else if !outputs.is_empty() {
1207 "model_answer"
1208 } else if !result.failures.is_empty() {
1209 "fail_closed_bad_action"
1210 } else {
1211 "model_silent"
1212 }
1213 }
1214
1215 /// Emit the `decision=` line for one TFTP event at the level its token deserves.
1216 ///
1217 /// `stage` names which of the four LLM call sites produced it (`RRQ`, `WRQ`,
1218 /// `ACK continuation`, `DATA block`), so a grep tells an operator *where* a transfer
1219 /// stopped as well as why.
1220 fn log_decision(
1221 log: &Log<'_>,
1222 decision: &str,
1223 stage: &str,
1224 peer_addr: SocketAddr,
1225 result: &crate::llm::ExecutionResult,
1226 ) {
1227 match decision {
1228 "model_answer" => log.info(format!(
1229 "TFTP {} from {} decision=model_answer",
1230 stage, peer_addr
1231 )),
1232 "model_reject" => log.info(format!(
1233 "TFTP {} from {} decision=model_reject (handler answered with an ERROR packet)",
1234 stage, peer_addr
1235 )),
1236 "fail_closed_bad_action" => {
1237 let detail = result
1238 .failures
1239 .iter()
1240 .map(|f| format!("{}: {}", f.action, f.error))
1241 .collect::<Vec<_>>()
1242 .join("; ");
1243 log.error(format!(
1244 "TFTP {} from {} decision=fail_closed_bad_action ({}); nothing was sent and \
1245 the transfer is left for the client to time out",
1246 stage, peer_addr, detail
1247 ))
1248 }
1249 _ => log.warn(format!(
1250 "TFTP {} from {} decision=model_silent; nothing was sent and the transfer is \
1251 left for the client to time out",
1252 stage, peer_addr
1253 )),
1254 }
1255 }
1256
1257 /// The opcode of a packet the handler produced, or `None` if it is too short to have one.
1258 ///
1259 /// Every action this protocol defines yields at least four bytes, so `None` means an
1260 /// action outside the declared set produced it — worth logging rather than indexing into.
1261 fn packet_opcode(packet: &[u8]) -> Option<u16> {
1262 if packet.len() < 4 {
1263 return None;
1264 }
1265 Some(u16::from_be_bytes([packet[0], packet[1]]))
1266 }
1267
1268 /// Parse RRQ/WRQ request packet
1269 fn parse_request(data: &[u8]) -> Result<(String, String)> {
1270 // Format: filename\0mode\0
1271 let null_positions: Vec<usize> = data
1272 .iter()
1273 .enumerate()
1274 .filter_map(|(i, &b)| if b == 0 { Some(i) } else { None })
1275 .collect();
1276
1277 if null_positions.len() < 2 {
1278 return Err(anyhow::anyhow!("Invalid TFTP request format"));
1279 }
1280
1281 let filename = String::from_utf8_lossy(&data[..null_positions[0]]).to_string();
1282 let mode =
1283 String::from_utf8_lossy(&data[null_positions[0] + 1..null_positions[1]]).to_string();
1284
1285 Ok((filename, mode))
1286 }
1287
1288 /// Build the ERROR packet a client gets when the LLM call behind a transfer fails.
1289 ///
1290 /// RFC 1350 defines error codes 0-7 and none of them means "try again", so both cases
1291 /// use code 0 ("Not defined, see error message") and the message says which. The
1292 /// packet is never a plausible-looking DATA or ACK: an LLM outage must not be
1293 /// indistinguishable from a successful transfer.
1294 fn llm_failure_error_packet(err: &anyhow::Error) -> Vec<u8> {
1295 if crate::llm::is_overload_error(err) {
1296 Self::build_error_packet(0, "Server overloaded, retry later")
1297 } else {
1298 Self::build_error_packet(0, "Internal error: LLM backend failure")
1299 }
1300 }
1301
1302 /// Answer an LLM failure with an ERROR packet and tear the transfer down.
1303 ///
1304 /// Every LLM call in a TFTP transfer routes its error branch through here. Two of the
1305 /// four used to write nothing at all, so the client sat in `recvfrom` until its own
1306 /// retransmit/timeout logic gave up with no indication of what went wrong - a partial
1307 /// transfer that simply stopped, which for a PXE boot looks like a corrupt image.
1308 #[allow(clippy::too_many_arguments)]
1309 async fn fail_transfer_on_llm_error(
1310 socket: &UdpSocket,
1311 peer_addr: SocketAddr,
1312 transfer_id: TransferId,
1313 stage: &str,
1314 err: &anyhow::Error,
1315 server_id: crate::state::ServerId,
1316 connection_id: ConnectionId,
1317 app_state: &Arc<AppState>,
1318 status_tx: &mpsc::UnboundedSender<String>,
1319 transfers: &Arc<Mutex<HashMap<TransferId, TftpTransfer>>>,
1320 ) {
1321 let log = Log::new(Some(&status_tx));
1322 // The backend failed. The client still gets an ERROR packet (a category, never the
1323 // error text — see `llm_failure_error_packet`) and the transfer is torn down cleanly,
1324 // but this is the outcome an operator greps for, so it is tagged and logged at ERROR.
1325 // The two categories are kept apart because one is retryable and one is not.
1326 let decision = if crate::utils::WireFailure::classify(err).is_overloaded() {
1327 "fail_closed_llm_overloaded"
1328 } else {
1329 "fail_closed_llm_error"
1330 };
1331 log.error(format!(
1332 "TFTP {} from {} decision={}: {} - sending ERROR and ending transfer",
1333 stage, peer_addr, decision, err
1334 ));
1335
1336 let packet = Self::llm_failure_error_packet(err);
1337 match socket.send_to(&packet, peer_addr).await {
1338 Ok(sent) => {
1339 app_state
1340 .update_connection_stats(
1341 server_id,
1342 connection_id,
1343 None,
1344 Some(sent as u64),
1345 None,
1346 Some(1),
1347 )
1348 .await;
1349 log.trace(format!(
1350 "TFTP sent ERROR packet (hex): {}",
1351 hex::encode(&packet)
1352 ));
1353 }
1354 Err(send_err) => {
1355 // Could not deliver even the fallback ERROR: genuinely cannot proceed.
1356 log.error(format!(
1357 "TFTP failed to deliver ERROR packet to {}: {}",
1358 peer_addr, send_err
1359 ));
1360 }
1361 }
1362
1363 transfers.lock().await.remove(&transfer_id);
1364 app_state
1365 .close_connection_on_server(server_id, connection_id)
1366 .await;
1367 }
1368
1369 /// Build TFTP ERROR packet
1370 fn build_error_packet(error_code: u16, message: &str) -> Vec<u8> {
1371 let mut packet = Vec::with_capacity(4 + message.len() + 1);
1372 packet.extend_from_slice(&5u16.to_be_bytes()); // Opcode ERROR
1373 packet.extend_from_slice(&error_code.to_be_bytes());
1374 packet.extend_from_slice(message.as_bytes());
1375 packet.push(0); // Null terminator
1376 packet
1377 }
1378}