[Dnsmasq-discuss] TFTP logging strangeness
Ferenc Wagner
wferi at niif.hu
Fri Sep 17 14:02:32 BST 2010
Hi,
Sorry if I'm becoming a pest, but I was unfortunate enogh to notice
another strangeness. Here are the logs:
Sep 17 12:56:55 n0 dnsmasq-tftp[10637]: sent /var/lib/tftpboot/pxelinux.0 to 192.168.31.43
Sep 17 12:56:55 n0 dnsmasq-tftp[10637]: error 0 TFTP Aborted received from 192.168.31.43
Sep 17 12:56:55 n0 dnsmasq-tftp[10637]: failed sending /var/lib/tftpboot/pxelinux.0 to 192.168.31.43
and the corresponding network dump:
Time Source sport Destination dport Size Info
12:56:55.638273 192.168.31.43 2070 192.168.31.33 69 69 Read Request, File: pxelinux.0\000, Transfer type: octet\000
12:56:55.638811 192.168.31.33 44394 192.168.31.43 2070 56 Option Acknowledgement
12:56:55.639331 192.168.31.43 2070 192.168.31.33 44394 59 Error Code, Code: Not defined, Message: TFTP Aborted\000
One thing is that pxelinux.0 wasn't actually sent in this case, that
message seems to be unconditionally output when the transmission fails.
(Why the PXE stack on the NIC aborts the transfer after successfully
negotiating the tsize option is beyond me, but that's unrelated.)
But it retries at once, with blksize negotiation instead (not shown):
Sep 17 12:56:55 n0 dnsmasq-tftp[10637]: sent /var/lib/tftpboot/pxelinux.0 to 192.168.31.43
Sep 17 12:57:13 n0 dnsmasq-tftp[10637]: unsupported request from 192.168.31.43
Sep 17 12:57:13 n0 kernel: [1036596.024038] Accepted: IN= OUT=szie-aotk SRC=192.168.31.33 DST=192.168.31.43 LEN=71 TOS=0x00 PREC=0x00 TTL=64 ID=10115 PROTO=UDP SPT=42668 DPT=2072 LEN=51 UID=0 GID=0
Sep 17 12:57:31 n0 dnsmasq-tftp[10637]: failed sending /var/lib/tftpboot/pxelinux.0 to 192.168.31.43
Again the corresponding network dump:
Time Source sport Destination dport Size Info
12:56:55.641492 192.168.31.43 2071 192.168.31.33 69 74 Read Request, File: pxelinux.0\000, Transfer type: octet\000
12:56:55.642821 192.168.31.33 43907 192.168.31.43 2071 57 Option Acknowledgement
12:56:55.643532 192.168.31.43 2071 192.168.31.33 43907 46 Acknowledgement, Block: 0
12:56:55.645010 192.168.31.33 43907 192.168.31.43 2071 1502 Data Packet, Block: 1
12:56:57.157363 192.168.31.33 43907 192.168.31.43 2071 1502 Data Packet, Block: 1
12:57:00.181397 192.168.31.33 43907 192.168.31.43 2071 1502 Data Packet, Block: 1
12:57:05.021365 192.168.31.33 43907 192.168.31.43 2071 1502 Data Packet, Block: 1
12:57:13.607268 192.168.31.43 2072 192.168.31.33 69 74 Acknowledgement, Block: 0
12:57:13.608470 192.168.31.33 42668 192.168.31.43 2072 85 Error Code, Code: Illegal TFTP Operation, Message: unsupported request from 192.168.31.43\000
12:57:14.110313 192.168.31.33 43907 192.168.31.43 2071 1502 Data Packet, Block: 1
Here we got an MTU problem: the TFTP data packet didn't get through
because of its size, so it's retransmitted in vain a couple of times,
then finally the client also retransmits its ACK (from a different
port!) Here the Linux TFTP connection tracking gets rightfully
confused, so the firewall logs the packet, but lets it through
nevertheless. Dnsmasq, receiving it, mistakes the retransmitted ACK for
a request packet, emits a confusing error message and an error packet,
terminating the stalled transfer, but later retransmits the doomed data
packet again.
Now, retransmitting the ACK from a different port is a bug in the PXE
ROM, there isn't much to do about that. But it would be more helpful
from dnsmasq to call them ACKs and not "unsupported requests". I think.
--
Cheers, :)
Feri.
More information about the Dnsmasq-discuss
mailing list