Bug 1328827
| Summary: | RFE: Evaluate RFC7440 for tftp | ||||||
|---|---|---|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 7 | Reporter: | Jan Synacek <jsynacek> | ||||
| Component: | tftp | Assignee: | Jan Synacek <jsynacek> | ||||
| Status: | CLOSED ERRATA | QA Contact: | Release Test Team <release-test-team-automation> | ||||
| Severity: | low | Docs Contact: | Lenka Špačková <lkuprova> | ||||
| Priority: | high | ||||||
| Version: | 7.3 | CC: | akarlsso, chayang, dgross, dyasny, extras-qa, jstodola, jsynacek, juzhang, lersek, lmiksik, noel.mcloughlin, pasik, pholica, salmy, sukulkar, xfu | ||||
| Target Milestone: | rc | Keywords: | FutureFeature, Patch, Performance, RFE | ||||
| Target Release: | --- | ||||||
| Hardware: | All | ||||||
| OS: | All | ||||||
| URL: | https://tools.ietf.org/html/rfc7440 | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | Doc Type: | Enhancement | |||||
| Doc Text: |
Support for the TFTP "windowsize" option has been implemented
With this update, support for the "windowsize" option according to RFC 7440 has been implemented in the Trivial File Transfer Protocol (TFTP) server and client. When the "windowsize" option is used, data blocks are sent in batches, which significantly improves throughput.
|
Story Points: | --- | ||||
| Clone Of: | 1314744 | Environment: | |||||
| Last Closed: | 2018-04-10 08:35:30 UTC | Type: | Bug | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Embargoed: | |||||||
| Bug Depends On: | 1314744 | ||||||
| Bug Blocks: | 1380361, 1420851, 1465901, 1466365 | ||||||
| Attachments: |
|
||||||
|
Comment 32
Laszlo Ersek
2018-02-01 17:59:15 UTC
Right, so I can see two problems with the code. Do you still have the VM? If I provide you with a new package, would you be able to test it? (In reply to Jan Synacek from comment #36) > Right, so I can see two problems with the code. Do you still have the VM? If > I provide you with a new package, would you be able to test it? Yes, absolutely; I'd be glad to help with testing! Jan, with "tftp-server-5.2-20.el7.test1.x86_64" from comment 38, the PXE boot progresses a bit farther, but ultimately it fails with very similar symptoms. I added a few "-v" options to "server_args" in "/etc/xinetd.d/tftp", and now the journal says, > in.tftpd[1807]: RRQ from 192.168.124.101 filename ipxe.efi > in.tftpd[1807]: unexpected packet ERROR block=8 > in.tftpd[1808]: RRQ from 192.168.124.101 filename ipxe.efi > in.tftpd[1808]: *** buffer overflow detected ***: in.tftpd terminated Here's a pcap as well. Non-verbose listing: > 16:27:58.619596 IP 192.168.124.101.1581 > 192.168.124.2.69: 38 RRQ > "ipxe.efi" octet tsize 0 blksize 1468 > 16:27:58.623289 IP 192.168.124.2.47680 > 192.168.124.101.1581: UDP, length > 28 > 16:27:58.623418 IP 192.168.124.101.1581 > 192.168.124.2.47680: UDP, length > 30 > 16:27:58.623608 IP 192.168.124.2.47680 > 192.168.124.101.1581: UDP, length > 22 > 16:27:58.630468 IP 192.168.124.101.1582 > 192.168.124.2.69: 30 RRQ > "ipxe.efi" octet blksize 1468 > 16:27:58.630567 IP 192.168.124.101 > 192.168.124.2: ICMP 192.168.124.101 > udp port 1581 unreachable, length 36 > 16:27:58.631433 IP 192.168.124.2.36436 > 192.168.124.101.1582: UDP, length > 15 > 16:27:58.631571 IP 192.168.124.101.1582 > 192.168.124.2.36436: UDP, length > 4 > 16:28:02.611713 IP 192.168.124.101.1582 > 192.168.124.2.36436: UDP, length > 4 > 16:28:02.611855 IP 192.168.124.2 > 192.168.124.101: ICMP 192.168.124.2 udp > port 36436 unreachable, length 40 Verbose listing of the same: > 16:27:58.619596 52:54:00:1b:10:3e > 52:54:00:0a:04:6c, ethertype IPv4 > (0x0800), length 80: (tos 0x0, ttl 64, id 49247, offset 0, flags [none], > proto UDP (17), length 66) > 192.168.124.101.1581 > 192.168.124.2.69: [udp sum ok] 38 RRQ > "ipxe.efi" octet tsize 0 blksize 1468 > 0x0000: 4500 0042 c05f 0000 4011 4093 c0a8 7c65 E..B._..@.@...|e > 0x0010: c0a8 7c02 062d 0045 002e 89f3 0001 6970 ..|..-.E......ip > 0x0020: 7865 2e65 6669 006f 6374 6574 0074 7369 xe.efi.octet.tsi > 0x0030: 7a65 0030 0062 6c6b 7369 7a65 0031 3436 ze.0.blksize.146 > 0x0040: 3800 8. > > 16:27:58.623289 52:54:00:0a:04:6c > 52:54:00:1b:10:3e, ethertype IPv4 > (0x0800), length 70: (tos 0x0, ttl 64, id 49049, offset 0, flags [none], > proto UDP (17), length 56) > 192.168.124.2.47680 > 192.168.124.101.1581: [bad udp cksum 0x79ee -> > 0x16ed!] UDP, length 28 > 0x0000: 4500 0038 bf99 0000 4011 4163 c0a8 7c02 E..8....@.Ac..|. > 0x0010: c0a8 7c65 ba40 062d 0024 79ee 0006 7473 ..|e.@.-.$y...ts > 0x0020: 697a 6500 3731 3535 3834 0062 6c6b 7369 ize.715584.blksi > 0x0030: 7a65 0031 3436 3800 ze.1468. > > 16:27:58.623418 52:54:00:1b:10:3e > 52:54:00:0a:04:6c, ethertype IPv4 > (0x0800), length 72: (tos 0x0, ttl 64, id 49248, offset 0, flags [none], > proto UDP (17), length 58) > 192.168.124.101.1581 > 192.168.124.2.47680: [udp sum ok] UDP, length > 30 > 0x0000: 4500 003a c060 0000 4011 409a c0a8 7c65 E..:.`..@.@...|e > 0x0010: c0a8 7c02 062d ba40 0026 4d57 0005 0008 ..|..-.@.&MW.... > 0x0020: 5573 6572 2061 626f 7274 6564 2074 6865 User.aborted.the > 0x0030: 2074 7261 6e73 6665 7200 .transfer. > > 16:27:58.623608 52:54:00:0a:04:6c > 52:54:00:1b:10:3e, ethertype IPv4 > (0x0800), length 64: (tos 0x0, ttl 64, id 49050, offset 0, flags [none], > proto UDP (17), length 50) > 192.168.124.2.47680 > 192.168.124.101.1581: [bad udp cksum 0x79e8 -> > 0x7028!] UDP, length 22 > 0x0000: 4500 0032 bf9a 0000 4011 4168 c0a8 7c02 E..2....@.Ah..|. > 0x0010: c0a8 7c65 ba40 062d 001e 79e8 0005 0000 ..|e.@.-..y..... > 0x0020: 556e 6578 7065 6374 6564 2070 6163 6b65 Unexpected.packe > 0x0030: 7400 t. > > 16:27:58.630468 52:54:00:1b:10:3e > 52:54:00:0a:04:6c, ethertype IPv4 > (0x0800), length 72: (tos 0x0, ttl 64, id 49249, offset 0, flags [none], > proto UDP (17), length 58) > 192.168.124.101.1582 > 192.168.124.2.69: [udp sum ok] 30 RRQ > "ipxe.efi" octet blksize 1468 > 0x0000: 4500 003a c061 0000 4011 4099 c0a8 7c65 E..:.a..@.@...|e > 0x0010: c0a8 7c02 062e 0045 0026 7875 0001 6970 ..|....E.&xu..ip > 0x0020: 7865 2e65 6669 006f 6374 6574 0062 6c6b xe.efi.octet.blk > 0x0030: 7369 7a65 0031 3436 3800 size.1468. > > 16:27:58.630567 52:54:00:1b:10:3e > 52:54:00:0a:04:6c, ethertype IPv4 > (0x0800), length 70: (tos 0x0, ttl 255, id 49250, offset 0, flags [none], > proto ICMP (1), length 56) > 192.168.124.101 > 192.168.124.2: ICMP 192.168.124.101 udp port 1581 > unreachable, length 36 > (tos 0x0, ttl 64, id 49050, offset 0, flags [none], proto UDP > (17), length 50) > 192.168.124.2.47680 > 192.168.124.101.1581: UDP, length 22 > 0x0000: 4500 0038 c062 0000 ff01 81a9 c0a8 7c65 E..8.b........|e > 0x0010: c0a8 7c02 0303 cc48 0000 0000 4500 0032 ..|....H....E..2 > 0x0020: bf9a 0000 4011 4168 c0a8 7c02 c0a8 7c65 ....@.Ah..|...|e > 0x0030: ba40 062d 001e 7028 .@.-..p( > > 16:27:58.631433 52:54:00:0a:04:6c > 52:54:00:1b:10:3e, ethertype IPv4 > (0x0800), length 57: (tos 0x0, ttl 64, id 49053, offset 0, flags [none], > proto UDP (17), length 43) > 192.168.124.2.36436 > 192.168.124.101.1582: [bad udp cksum 0x79e1 -> > 0xedb7!] UDP, length 15 > 0x0000: 4500 002b bf9d 0000 4011 416c c0a8 7c02 E..+....@.Al..|. > 0x0010: c0a8 7c65 8e54 062e 0017 79e1 0006 626c ..|e.T....y...bl > 0x0020: 6b73 697a 6500 3134 3638 00 ksize.1468. > > 16:27:58.631571 52:54:00:1b:10:3e > 52:54:00:0a:04:6c, ethertype IPv4 > (0x0800), length 46: (tos 0x0, ttl 64, id 49251, offset 0, flags [none], > proto UDP (17), length 32) > 192.168.124.101.1582 > 192.168.124.2.36436: [udp sum ok] UDP, length 4 > 0x0000: 4500 0020 c063 0000 4011 40b1 c0a8 7c65 E....c..@.@...|e > 0x0010: c0a8 7c02 062e 8e54 000c f196 0004 0000 ..|....T........ > > 16:28:02.611713 52:54:00:1b:10:3e > 52:54:00:0a:04:6c, ethertype IPv4 > (0x0800), length 46: (tos 0x0, ttl 64, id 49252, offset 0, flags [none], > proto UDP (17), length 32) > 192.168.124.101.1582 > 192.168.124.2.36436: [udp sum ok] UDP, length 4 > 0x0000: 4500 0020 c064 0000 4011 40b0 c0a8 7c65 E....d..@.@...|e > 0x0010: c0a8 7c02 062e 8e54 000c f196 0004 0000 ..|....T........ > > 16:28:02.611855 52:54:00:0a:04:6c > 52:54:00:1b:10:3e, ethertype IPv4 > (0x0800), length 74: (tos 0xc0, ttl 64, id 51031, offset 0, flags [none], > proto ICMP (1), length 60) > 192.168.124.2 > 192.168.124.101: ICMP 192.168.124.2 udp port 36436 > unreachable, length 40 > (tos 0x0, ttl 64, id 49252, offset 0, flags [none], proto UDP > (17), length 32) > 192.168.124.101.1582 > 192.168.124.2.36436: [udp sum ok] UDP, length 4 > 0x0000: 45c0 003c c757 0000 4001 38f1 c0a8 7c02 E..<.W..@.8...|. > 0x0010: c0a8 7c65 0303 76d3 0000 0000 4500 0020 ..|e..v.....E... > 0x0020: c064 0000 4011 40b0 c0a8 7c65 c0a8 7c02 .d..@.@...|e..|. > 0x0030: 062e 8e54 000c f196 0004 0000 ...T........ Laszlo and Jan, I need to confirm 2 questions with you. Q1) Does QE need to file a new bug to track this problem? Q2) According to comment32. It only is tftp-server package's problem. no OVMF's problem. Does QE need to test previous tftp-server version + the latest OVMf? In addition, I updated tftp-server package from tftp-server-5.2-20.el7 to tftp-server-5.2-13.el7.x86_64, I encountered another error.
1)From tftp-server host's message log:
Feb 5 15:54:47 localhost dhcpd: DHCPDISCOVER from 08:9e:01:c2:6d:6e via eth0
Feb 5 15:54:48 localhost dhcpd: DHCPOFFER on 192.168.1.2 to 08:9e:01:c2:6d:6e via eth0
Feb 5 15:54:51 localhost dhcpd: DHCPREQUEST for 192.168.1.2 (192.168.1.100) from 08:9e:01:c2:6d:6e via eth0
Feb 5 15:54:51 localhost dhcpd: DHCPACK on 192.168.1.2 to 08:9e:01:c2:6d:6e via eth0
Feb 5 15:54:51 localhost xinetd[2667]: START: tftp pid=2675 from=192.168.1.2
Feb 5 15:54:51 localhost xinetd[2675]: execv( /usr/sbin/in.tftpd ) failed: Exec format error (errno = 8)
Feb 5 15:54:51 localhost xinetd[2667]: EXIT: tftp status=0 pid=2675 duration=0(sec)
Feb 5 15:54:55 localhost xinetd[2667]: START: tftp pid=2678 from=192.168.1.2
Feb 5 15:54:55 localhost xinetd[2678]: execv( /usr/sbin/in.tftpd ) failed: Exec format error (errno = 8)
Feb 5 15:54:55 localhost xinetd[2667]: EXIT: tftp status=0 pid=2678 duration=0(sec)
Feb 5 15:54:59 localhost xinetd[2667]: START: tftp pid=2681 from=192.168.1.2
Feb 5 15:54:59 localhost xinetd[2681]: execv( /usr/sbin/in.tftpd ) failed: Exec format error (errno = 8)
Feb 5 15:54:59 localhost xinetd[2667]: EXIT: tftp status=0 pid=2681 duration=0(sec)
Feb 5 15:55:03 localhost xinetd[2667]: START: tftp pid=2684 from=192.168.1.2
Feb 5 15:55:03 localhost xinetd[2684]: execv( /usr/sbin/in.tftpd ) failed: Exec format error (errno = 8)
Feb 5 15:55:03 localhost xinetd[2667]: EXIT: tftp status=0 pid=2684 duration=0(sec)
Feb 5 15:55:07 localhost xinetd[2667]: START: tftp pid=2687 from=192.168.1.2
Feb 5 15:55:07 localhost xinetd[2687]: execv( /usr/sbin/in.tftpd ) failed: Exec format error (errno = 8)
Feb 5 15:55:07 localhost xinetd[2667]: EXIT: tftp status=0 pid=2687 duration=0(sec)
Feb 5 15:55:11 localhost xinetd[2667]: START: tftp pid=2690 from=192.168.1.2
Feb 5 15:55:11 localhost xinetd[2690]: execv( /usr/sbin/in.tftpd ) failed: Exec format error (errno = 8)
Feb 5 15:55:11 localhost xinetd[2667]: EXIT: tftp status=0 pid=2690 duration=0(sec)
2)From ovmf part of log:
.....
[Bds] Expand PciRoot(0x0)/Pci(0x6,0x0)/MAC(089E01C26D6E,0x1) -> <null string>
Process PlatformRecovery0000 (Default PlatformRecovery) ...
SataControllerStart START
SataControllerStart error return status = Already started
BlockSize : 2048
LastBlock : 4F2
BlockSize : 2048
LastBlock : 1C9CFF
SataControllerStart START
SataControllerStart error return status = Already started
SataControllerStart START
SataControllerStart error return status = Already started
BlockSize : 2048
LastBlock : 4F2
BlockSize : 2048
LastBlock : 1C9CFF
SataControllerStart START
SataControllerStart error return status = Already started
BlockSize : 2048
LastBlock : 4F2
BlockSize : 2048
LastBlock : 1C9CFF
FatDiskIo: Cache Page OutBound occurred!
FSOpen: Open '\EFI\BOOT\BOOTX64.EFI' Success
....
Laszlo,
If your configuration works with tftp-server-5.2-13.el7.x86_64. Can you attach your configuration to bz? Thanks.
e.g 1. /etc/xineted.d/tftp
2. /var/lib/tftpboot/grub.cfg
3. /etc/dhcp/dhcpd.conf
(In reply to FuXiangChun from comment #40) > Laszlo and Jan, > > I need to confirm 2 questions with you. > > Q1) Does QE need to file a new bug to track this problem? No, use this one, please. > Q2) According to comment32. It only is tftp-server package's problem. no > OVMF's problem. Does QE need to test previous tftp-server version + the > latest OVMf? If you have the capacity, yes, please make sure that the old version works as expected with the latest OVMf. Moving to assigned based on comment 42 (In reply to FuXiangChun from comment #41) > Laszlo, > If your configuration works with tftp-server-5.2-13.el7.x86_64. Yes, it does. > Can you attach your configuration to bz? Thanks. > > e.g 1. /etc/xineted.d/tftp > 2. /var/lib/tftpboot/grub.cfg > 3. /etc/dhcp/dhcpd.conf The configuration for this setup is pretty complex. The reason is that on a NAT-et virtual network (virbrX), libvirt can generally set up its own DHCP/PXE infrastructure. DHCP is enabled by default, PXE is optional. Nonetheless, in either configuration, these services are provided by a dnsmasq instance that libvirtd fires up. Therefore, in order to work with the tftp-server component, *two* virtual machines are needed, on a dedicated virbrX network, and libivrtd's DHCP and PXE services must be *both* disabled on that network. Then, one VM can be configured for PXE booting (so it should have a single NIC, on the virbrX network in question), and another VM should be configured with *two* NICs -- one NIC should be in the virbrX network (for serving DHCP and PXE), and the other NIC should be on the "default" virbr network (so that we can ssh into the "server VM" from the virtualization host, for administration purposes, regardless of the state of the network that we use for PXE testing). As I mentioned in comment 32, the configuration was written up in detail earlier, in the following comments (follow them in the order below): - bug 1462351 comment 9 - bug 1462351 comment 15 section (0) - bug 1462351 comment 15 section (2) (Either way I will attach my config files that you asked for.) Created attachment 1391544 [details]
libvirt network XML for cross-VM DHCP/TFTP
Test results with the "tftp-server-5.2-20.el7.test2.x86_64" build (comment 43): The results are somewhat similar to the test1 results in comment 39. The "unexpected packet" log message and response datagram are gone, but ultimately the boot fails with the buffer overflow seen earlier: > xinetd[1196]: START: tftp pid=1809 from=192.168.124.101 > in.tftpd[1810]: RRQ from 192.168.124.101 filename ipxe.efi > in.tftpd[1810]: Error code 0: > in.tftpd[1811]: RRQ from 192.168.124.101 filename ipxe.efi > in.tftpd[1811]: *** buffer overflow detected ***: in.tftpd terminated non-verbose pkt log: 15:40:38.140196 IP 192.168.124.101.1307 > 192.168.124.2.69: 38 RRQ "ipxe.efi" octet tsize 0 blksize 1468 15:40:38.143256 IP 192.168.124.2.49107 > 192.168.124.101.1307: UDP, length 28 15:40:38.143348 IP 192.168.124.101.1307 > 192.168.124.2.49107: UDP, length 30 15:40:38.148263 IP 192.168.124.101.1308 > 192.168.124.2.69: 30 RRQ "ipxe.efi" octet blksize 1468 15:40:38.148966 IP 192.168.124.2.49712 > 192.168.124.101.1308: UDP, length 15 15:40:38.149056 IP 192.168.124.101.1308 > 192.168.124.2.49712: UDP, length 4 15:40:42.142945 IP 192.168.124.101.1308 > 192.168.124.2.49712: UDP, length 4 15:40:42.143055 IP 192.168.124.2 > 192.168.124.101: ICMP 192.168.124.2 udp port 49712 unreachable, length 40 The following message: > in.tftpd[1811]: *** buffer overflow detected ***: in.tftpd terminated is from glibc / _FORTIFY_SOURCE=2. Glibc catches the buffer overflow and calls abort(). In turn I tried to capture a coredump, so that we can look at a backtrace in tftp-server. However, systemd and/or xinetd are too clever for their own good, and they somehow prevent abrt from collecting a coredump for tftp-server. (Yes, I checked that coredumps are enabled otherwise, and abrt works as expected: # sleep 100 & [1] 3800 # kill -SEGV %1 [1]+ Segmentation fault (core dumped) sleep 100 # ls -l core.* -rw-------. 1 root root 380928 Feb 5 16:13 core.3800 # abrt-cli list id ... reason: sleep killed by SIGSEGV ... ) Enabling core dumps shouldn't be rocket science, but apparently I'm not the only one failing at it <https://access.redhat.com/solutions/4896>. (In reply to Laszlo Ersek from comment #53) > The following message: > > > in.tftpd[1811]: *** buffer overflow detected ***: in.tftpd terminated > > is from glibc / _FORTIFY_SOURCE=2. Glibc catches the buffer overflow and > calls abort(). > > In turn I tried to capture a coredump, so that we can look at a backtrace in > tftp-server. However, systemd and/or xinetd are too clever for their own > good, and they somehow prevent abrt from collecting a coredump for > tftp-server. Can you run the server by hand and attaching gdb to it? Also, you can try setting DumpCore=no in /etc/systemd/system.conf, then running 'ulimit -c unlimited'. That might work. Thanks Laszlo, I try to set up it with your configuration. But I don't use libvirt. So it is not exactly the same with your steps. As I am not familiar with libvirt. I want to use qemu-kvm to setup it first. I encountered an issue again. If you think this problem is not clear(don't know why). I will give up this way. and will use libvirt to setup it. I attached a screenshop. Thanks again. Created attachment 1392030 [details]
ipxe.efi or ipxe.cfg problem
Hello Jan, I'm going to test your v3 test build from comment 54 in a minute, but first I'd like to react to your question in comment 55. Last night I struggled for *hours* with an attempt to get a coredump / backtrace, and it's simply not there. I grabbed the SRPM for your test2 package, prepared it locally ("rpmbuild -bp"), and built it manually, using the commands that I found in the spec file. Get this: if I build the test2 package *without* -D_FORTIFY_SOURCE=2, then the PXE boot completes fine; there is no crash, no glibc-caught buffer overflow or anything similar. If I build test2 *with* -D_FORTIFY_SOURCE=2 (plus the required optimization switch -O), then the buffer overflow is detected. So, working with the -D_FORTIFY_SOUCRE=2 build, I tried to locate the origin of the buffer overflow. First of all, there is *no* SIGABRT raised anywhere *at all*. I ran tftpd with the "-L" option (to prevent daemonization), and configured gdb to follow both parent and child across fork() (of course, for separate runs; both cannot be done at the same time). There is *no* SIGABRT. And, even after I set breakpoints on the glibc functions that are related to the fortification / buffer overflow catching, those breakpoints *never* triggered. I was completely unable to get a backtrace. It's unfathomable. My final attempt was to add a large amount of debug printf()s to the source code, basically tracking down where the "buffer overflow detected" message came from -- I hoped to narrow down the location. Incredibly, this approach failed as well. Consider the following (plase click the "Unwrap comments" link near the top, if the source listing is wrapped): [tftpd/tftpd.c] 1506 /* 1507 * Send the requested file. 1508 */ 1509 static void tftp_sendfile(const struct formats *pf, struct tftphdr *oap, int oacklen, char *filename) 1510 { 1511 struct tftphdr *tp = (struct tftphdr *)pktbuf; 1512 unsigned short tp_opcode, tp_block; 1513 int retries = RETRIES; 1514 int timed_out = 0; 1515 int n, r = 0; 1516 (void) pf; 1517 1518 set_verbose(verbosity); 1519 if (oap) { 1520 printf("-- %s:%d\n", __FILE__, __LINE__); 1521 do { 1522 printf("-- %s:%d\n", __FILE__, __LINE__); 1523 if (send(peer, oap, oacklen, 0) != oacklen) { 1524 printf("-- %s:%d\n", __FILE__, __LINE__); 1525 syslog(LOG_WARNING, "tftpd: oack: %m\n"); 1526 goto abort; 1527 } 1528 1529 printf("-- %s:%d\n", __FILE__, __LINE__); 1530 n = recv_with_timeout(peer, pktbuf, sizeof(pktbuf), g_timeout); 1531 printf("-- %s:%d\n", __FILE__, __LINE__); 1532 if (n < 0) { 1533 printf("-- %s:%d\n", __FILE__, __LINE__); 1534 syslog(LOG_WARNING, "tftpd: recv: %m"); 1535 goto abort; 1536 } else if (n == 0) { 1537 printf("-- %s:%d\n", __FILE__, __LINE__); 1538 if (--retries <= 0) { 1539 printf("-- %s:%d\n", __FILE__, __LINE__); 1540 timed_out = 1; 1541 goto abort; 1542 } 1543 printf("-- %s:%d\n", __FILE__, __LINE__); 1544 continue; 1545 } 1546 1547 printf("-- %s:%d\n", __FILE__, __LINE__); 1548 tp_opcode = ntohs(tp->th_opcode); 1549 tp_block = ntohs(tp->th_block); 1550 1551 if (tp_opcode == ERROR) { 1552 char error[ERROR_MAXLEN]; 1553 1554 printf("-- %s:%d\n", __FILE__, __LINE__); 1555 format_error(error); 1556 syslog(LOG_WARNING, "%s", error); 1557 goto abort; 1558 } else if (!(tp_opcode == ACK && tp_block == 0)) { 1559 printf("-- %s:%d\n", __FILE__, __LINE__); 1560 syslog(LOG_WARNING, "unexpected packet %s block=%u", opcode_to_str(tp_opcode), tp_block); 1561 send_error(peer, NULL, "Unexpected packet"); 1562 exit(1); 1563 } 1564 printf("-- %s:%d\n", __FILE__, __LINE__); 1565 } while (n == 0); 1566 printf("-- %s:%d\n", __FILE__, __LINE__); 1567 } 1568 1569 printf("-- %s:%d\n", __FILE__, __LINE__); 1570 r = sender(peer, NULL, segsize, windowsize, TIMEOUT, rollover_val, file, NULL); 1571 1572 printf("-- %s:%d\n", __FILE__, __LINE__); 1573 tmp_p = (char *)inet_ntop(from.sa.sa_family, SOCKADDR_P(&from), 1574 tmpbuf, INET6_ADDRSTRLEN); 1575 printf("-- %s:%d\n", __FILE__, __LINE__); 1576 if (!tmp_p) { 1577 printf("-- %s:%d\n", __FILE__, __LINE__); 1578 tmp_p = tmpbuf; 1579 strcpy(tmpbuf, "???"); 1580 } 1581 printf("-- %s:%d\n", __FILE__, __LINE__); 1582 syslog(LOG_NOTICE, "Client %s finished %s", tmp_p, filename); 1583 abort: 1584 printf("-- %s:%d\n", __FILE__, __LINE__); 1585 if (timed_out || r == E_TIMED_OUT) 1586 syslog(LOG_NOTICE, "Client %s timed out", tmp_p); 1587 fclose(file); 1588 } Here's the output, produced while serving the OVMF PXE client: > -- tftpd.c:1520 > -- tftpd.c:1522 > -- tftpd.c:1529 > -- tftpd.c:1531 > -- tftpd.c:1547 > -- tftpd.c:1554 > -- tftpd.c:1584 > -- tftpd.c:1520 > -- tftpd.c:1522 > -- tftpd.c:1529 > -- tftpd.c:1531 > -- tftpd.c:1547 > -- tftpd.c:1564 > -- tftpd.c:1566 > -- tftpd.c:1569 > *** buffer overflow detected ***: tftpd/tftpd terminated There are two RRQs coming in, which is why we see two sequences starting at line 1520. In the first sequence, OVMF aborts the transfer (recall "User aborted the transfer"); this is why the block around line 1554 is taken. We jump to line 1584, and the first sequence (RRQ) ends. In the second sequence, we proceed through lines 1564 and 1566, meaning that recv_with_timeout() returned a positive value. We reach line 1569, but we never reach line 1572. This implies the sender() call does something nasty, on line 1570, right? Wrong. My debug patch had added more printfs(): [common/common.c] 310 int sender(int sockfd, 311 union sock_addr *server, 312 int blocksize, 313 int windowsize, 314 int timeout, 315 int rollover, 316 FILE *fp, 317 unsigned long *sent) 318 { 319 struct tftphdr *tp = (struct tftphdr *)pktbuf; 320 unsigned short tp_opcode, tp_block; 321 unsigned short block = 1; 322 unsigned long amount = 0; 323 int l_timeout = timeout; 324 int window = 1; 325 int seek = 0; 326 int retries; 327 size_t size; 328 int done = 0; 329 int n; 330 331 retries = RETRIES; 332 do { 333 printf("-- %s:%d\n", __FILE__, __LINE__); 334 size = read_data(fp, blocksize, block, seek, tp); 335 if (size == 0 && ferror(fp)) { 336 send_error(sockfd, server, "Error while reading the file"); 337 return E_FAILED_TO_READ; 338 } 339 printf("-- %s:%d\n", __FILE__, __LINE__); Notice that line 333 from "common.c" is *never* logged. So basically glibc detects a buffer overflow *after* line 1569 in "tftpd.c", but *before* line 333 in "common.c". I read up on -D_FORTIFY_SOUCRE=2, and according to the documentation, it can trigger spurious failures in correct (standards-conformant) C code. So either there is such a corner case in tftpd somewhere, or there really is an elusive buffer overflow. ... Hold on, I should note that -D_FORTIFY_SOUCRE=1 results in the same symptom as well (buffer overflow detected); however, the debug trace is different in this case (quoting just the second sequence): > -- tftpd.c:1520 > -- tftpd.c:1522 > -- tftpd.c:1529 > -- tftpd.c:1531 > -- tftpd.c:1547 > -- tftpd.c:1564 > -- tftpd.c:1566 > -- tftpd.c:1569 > -- common.c:333 > *** buffer overflow detected ***: tftpd/tftpd terminated In this case "common.c:333" is logged (but line 339 is not). Let me dig a bit more; perhaps I can trace read_data() more closely (with -D_FORTIFY_SOUCRE=1). FuXiangChun, the ipxe.cfg file is not found in the tftp directory. It's possible that you haven't restored the SELinux context on it. Please go through my earlier steps carefully; I mentioned "restorecon" in bug 1462351 comment 9 bullet (g). Re comment 58; I failed to dig down read_data(), using -D_FORTIFY_SOURCE=1. I added a bunch of printf()s to read_data(), but none of those are printed. The "test3" build fails with the following journal messages:
> Feb 06 13:01:29 ovmf-rhel7-q35 dhcpd[1440]: DHCPDISCOVER from 52:54:00:1b:10:3e via eth1
> Feb 06 13:01:30 ovmf-rhel7-q35 dhcpd[1440]: DHCPOFFER on 192.168.124.101 to 52:54:00:1b:10:3e via eth1
> Feb 06 13:01:32 ovmf-rhel7-q35 dhcpd[1440]: DHCPREQUEST for 192.168.124.101 (192.168.124.2) from 52:54:00:1b:10:3e via eth1
> Feb 06 13:01:32 ovmf-rhel7-q35 dhcpd[1440]: DHCPACK on 192.168.124.101 to 52:54:00:1b:10:3e via eth1
> Feb 06 13:01:32 ovmf-rhel7-q35 in.tftpd[1874]: RRQ from 192.168.124.101 filename ipxe.efi
> Feb 06 13:01:32 ovmf-rhel7-q35 in.tftpd[1874]: Error code 8: User aborted the transfer
> Feb 06 13:01:32 ovmf-rhel7-q35 in.tftpd[1875]: RRQ from 192.168.124.101 filename ipxe.efi
> Feb 06 13:01:32 ovmf-rhel7-q35 in.tftpd[1875]: *** buffer overflow detected ***: in.tftpd terminated
I'll attach the packet capture next.
Thanks for the detailed info. And yeah, I can't reproduce that even with the same sequence of packets... I have no idea where the overflow comes from. Could you also try running it under valgrind? Also, check if the 'segsize' variable in sender() is actually what was negotiated in the options. Wow, valgrind was an awesome idea; this is what I get (using the test3 build): ==1867== Process terminating with default action of signal 6 (SIGABRT): dumping core ==1867== at 0x52911B7: raise (raise.c:56) ==1867== by 0x52928A7: abort (abort.c:90) ==1867== by 0x52D3C76: __libc_message (libc_fatal.c:196) ==1867== by 0x5373626: __fortify_fail (fortify_fail.c:31) ==1867== by 0x53717A1: __chk_fail (chk_fail.c:28) ==1867== by 0x5371E8B: __fread_chk (fread_chk.c:39) ==1867== by 0x10F5A3: UnknownInlinedFun (stdio2.h:290) ==1867== by 0x10F5A3: UnknownInlinedFun (common.c:130) ==1867== by 0x10F5A3: sender (common.c:332) ==1867== by 0x10C970: tftp_sendfile (tftpd.c:1555) ==1867== by 0x10CF78: tftp (tftpd.c:1112) ==1867== by 0x10BF5F: main (tftpd.c:982) Nice, thanks! And it's pretty clear where the problem is right now... fread() is using a 512-byte buffer to read the negotiated size of ~1400 bytes into. Silly me. (In reply to Jan Synacek from comment #66) > v4: [...] The test4 build works fine for me. First I tested it (successfully) with an iPXE payload: > dhcpd[1447]: DHCPDISCOVER from 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPOFFER on 192.168.124.101 to 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPREQUEST for 192.168.124.101 (192.168.124.2) from > 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPACK on 192.168.124.101 to 52:54:00:1b:10:3e via eth1 > xinetd[1197]: START: tftp pid=1823 from=192.168.124.101 > in.tftpd[1824]: RRQ from 192.168.124.101 filename ipxe.efi > in.tftpd[1824]: Error code 8: User aborted the transfer > in.tftpd[1825]: RRQ from 192.168.124.101 filename ipxe.efi > in.tftpd[1825]: Client 192.168.124.101 finished ipxe.efi > dhcpd[1447]: DHCPDISCOVER from 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPOFFER on 192.168.124.100 to 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPDISCOVER from 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPOFFER on 192.168.124.100 to 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPREQUEST for 192.168.124.100 (192.168.124.2) from > 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPACK on 192.168.124.100 to 52:54:00:1b:10:3e via eth1 > in.tftpd[1835]: RRQ from 192.168.124.100 filename ipxe.cfg > in.tftpd[1835]: Client 192.168.124.100 finished ipxe.cfg > in.tftpd[1836]: RRQ from 192.168.124.100 filename > images/RHEL-7.4-20170616.3/vmlinuz > in.tftpd[1836]: Client 192.168.124.100 finished > images/RHEL-7.4-20170616.3/vmlinuz > in.tftpd[1837]: RRQ from 192.168.124.100 filename > images/RHEL-7.4-20170616.3/initrd.img > in.tftpd[1837]: Client 192.168.124.100 finished > images/RHEL-7.4-20170616.3/initrd.img > dhcpd[1447]: DHCPDISCOVER from 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPOFFER on 192.168.124.101 to 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPREQUEST for 192.168.124.101 (192.168.124.2) from > 52:54:00:1b:10:3e via eth1 > dhcpd[1447]: DHCPACK on 192.168.124.101 to 52:54:00:1b:10:3e via eth1 Then I tested it (again successfully) with a shim/grub payload: > dhcpd[1934]: DHCPDISCOVER from 52:54:00:1b:10:3e via eth1 > dhcpd[1934]: DHCPOFFER on 192.168.124.101 to 52:54:00:1b:10:3e via eth1 > dhcpd[1934]: DHCPREQUEST for 192.168.124.101 (192.168.124.2) from > 52:54:00:1b:10:3e via eth1 > dhcpd[1934]: DHCPACK on 192.168.124.101 to 52:54:00:1b:10:3e via eth1 > in.tftpd[1938]: RRQ from 192.168.124.101 filename shim.efi > in.tftpd[1938]: Error code 8: User aborted the transfer > in.tftpd[1939]: RRQ from 192.168.124.101 filename shim.efi > in.tftpd[1939]: Client 192.168.124.101 finished shim.efi > in.tftpd[1940]: RRQ from 192.168.124.101 filename grubx64.efi > in.tftpd[1940]: Client 192.168.124.101 finished grubx64.efi > in.tftpd[1941]: RRQ from 192.168.124.101 filename > /grub.cfg-01-52-54-00-1b-10-3e- > in.tftpd[1941]: Client 192.168.124.101 File not found > /grub.cfg-01-52-54-00-1b-10-3e- > in.tftpd[1941]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1942]: RRQ from 192.168.124.101 filename /grub.cfg-C0A87C65 > in.tftpd[1942]: Client 192.168.124.101 File not found /grub.cfg-C0A87C65 > in.tftpd[1942]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1943]: RRQ from 192.168.124.101 filename /grub.cfg-C0A87C6 > in.tftpd[1943]: Client 192.168.124.101 File not found /grub.cfg-C0A87C6 > in.tftpd[1943]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1944]: RRQ from 192.168.124.101 filename /grub.cfg-C0A87C > in.tftpd[1944]: Client 192.168.124.101 File not found /grub.cfg-C0A87C > in.tftpd[1944]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1945]: RRQ from 192.168.124.101 filename /grub.cfg-C0A87 > in.tftpd[1945]: Client 192.168.124.101 File not found /grub.cfg-C0A87 > in.tftpd[1945]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1946]: RRQ from 192.168.124.101 filename /grub.cfg-C0A8 > in.tftpd[1946]: Client 192.168.124.101 File not found /grub.cfg-C0A8 > in.tftpd[1946]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1947]: RRQ from 192.168.124.101 filename /grub.cfg-C0A > in.tftpd[1947]: Client 192.168.124.101 File not found /grub.cfg-C0A > in.tftpd[1947]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1948]: RRQ from 192.168.124.101 filename /grub.cfg-C0 > in.tftpd[1948]: Client 192.168.124.101 File not found /grub.cfg-C0 > in.tftpd[1948]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1949]: RRQ from 192.168.124.101 filename /grub.cfg-C > in.tftpd[1949]: Client 192.168.124.101 File not found /grub.cfg-C > in.tftpd[1949]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1950]: RRQ from 192.168.124.101 filename /grub.cfg > in.tftpd[1950]: Client 192.168.124.101 finished /grub.cfg > in.tftpd[1951]: RRQ from 192.168.124.101 filename /grub.cfg > in.tftpd[1951]: Client 192.168.124.101 finished /grub.cfg > in.tftpd[1952]: RRQ from 192.168.124.101 filename > /EFI/redhat/x86_64-efi/command.lst > in.tftpd[1952]: Client 192.168.124.101 File not found > /EFI/redhat/x86_64-efi/command.lst > in.tftpd[1952]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1953]: RRQ from 192.168.124.101 filename > /EFI/redhat/x86_64-efi/fs.lst > in.tftpd[1953]: Client 192.168.124.101 File not found > /EFI/redhat/x86_64-efi/fs.lst > in.tftpd[1953]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1954]: RRQ from 192.168.124.101 filename > /EFI/redhat/x86_64-efi/crypto.lst > in.tftpd[1954]: Client 192.168.124.101 File not found > /EFI/redhat/x86_64-efi/crypto.lst > in.tftpd[1954]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1955]: RRQ from 192.168.124.101 filename > /EFI/redhat/x86_64-efi/terminal.lst > in.tftpd[1955]: Client 192.168.124.101 File not found > /EFI/redhat/x86_64-efi/terminal.lst > in.tftpd[1955]: sending NAK (1, File not found) to 192.168.124.101 > in.tftpd[1956]: RRQ from 192.168.124.101 filename /grub.cfg > in.tftpd[1956]: Client 192.168.124.101 finished /grub.cfg > in.tftpd[1957]: RRQ from 192.168.124.101 filename /grub.cfg > in.tftpd[1957]: Client 192.168.124.101 finished /grub.cfg > in.tftpd[1958]: RRQ from 192.168.124.101 filename /grub.cfg > in.tftpd[1958]: Client 192.168.124.101 finished /grub.cfg > in.tftpd[1967]: RRQ from 192.168.124.101 filename > images/RHEL-7.4-20170616.3/vmlinuz > in.tftpd[1967]: Client 192.168.124.101 finished > images/RHEL-7.4-20170616.3/vmlinuz > in.tftpd[1968]: RRQ from 192.168.124.101 filename > images/RHEL-7.4-20170616.3/initrd.img > in.tftpd[1968]: Client 192.168.124.101 finished > images/RHEL-7.4-20170616.3/initrd.img > dhcpd[1934]: DHCPDISCOVER from 52:54:00:1b:10:3e via eth1 > dhcpd[1934]: DHCPOFFER on 192.168.124.101 to 52:54:00:1b:10:3e via eth1 > dhcpd[1934]: DHCPREQUEST for 192.168.124.101 (192.168.124.2) from > 52:54:00:1b:10:3e via eth1 > dhcpd[1934]: DHCPACK on 192.168.124.101 to 52:54:00:1b:10:3e via eth1 Thank you Jan! Laszlo, Thank you for providing such detailed information. I have set up a complete test environment. And tftp-server-5.2-13.el7.x86_64 + OVMF-20171011-4.git92d07e48907f.el7.noarch works well. (In reply to FuXiangChun from comment #68) > Laszlo, > > Thank you for providing such detailed information. I have set up a complete > test environment. And tftp-server-5.2-13.el7.x86_64 + > OVMF-20171011-4.git92d07e48907f.el7.noarch works well. Thank you for checking! QE re-tested the latest tftp package tftp-5.2-22.el7.x86_64 + OVMF-20171011-4.git92d07e48907f.el7 works well. RHEL guest installation is successful via ipxe. (Note for the future: the edk2 TFTP client (which is built into OVMF) might grow support for the windowsize option. See <https://bugzilla.tianocore.org/show_bug.cgi?id=886>.) Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHEA-2018:0660 |