<div dir="ltr"><div>Hello Ladi,</div><div><br></div><div>Thank you a lot for looking into this issue and writing patches about the queue size. The patch set looks good to me.</div><div><br></div><div><span class="gmail-im" style="font-size:21px">>> I haven't captured DHCP packets (because I'm unsure how to do so in GCE's<br>>> fully managed DHCP server), but I guess DHCPACK is actually sent from the<br>>> DHCP server but somehow iPXE missed it.<br>><br></span><span style="font-size:21px">> Do you see any interesting log output with DEBUG=virtio-net,virtio-pci ?</span><br></div><div><br></div><div>Did not see any interesting log. No error about TX is printed, and it just fails to receive DHCPACK.</div><div><br></div><div>So, for ease of debugging with capturing packets, I tried to do `imgfetch http://...` with a static IP address (`set net0/ip`) instead.<br></div><div><br></div><div>The result implies that "iPXE believes it has sent the second Ethernet packet without an error, but it is not sent actually".</div><div><br></div><div>This assumption is consistent with my report about DHCP.</div><div>iPXE can successfully send the 1st packet (DHCPDISCOVER), but seems failing to send the 2nd packet (DHCPREQUEST). It should be the reason why it cannot receive DHCPACK.</div><div><br></div><div><br></div><div>Here is the log. In the client log, we can see "TX ... PSH ACK", but it is not received on the server side.</div><div><br></div><div>=== iPXE Client 10.146.0.10 (DEBUG=virtio-net:7,virtio-pci:7,tcp:7,ipv4:7 CONFIG=cloud, 26050fd4 with Ladi's 4 great patches) ===</div><div><br></div><div>    iPXE> imgfetch <a href="http://10.146.0.2/a.ipxe">http://10.146.0.2/a.ipxe</a></div><div>    <a href="http://10.146.0.2/a.ipxe...TCP">http://10.146.0.2/a.ipxe...TCP</a> 0x12eda4 allocated</div><div>    TCP 0x12eda4 transitioned from CLOSED to SYN_SENT</div><div>    TCP 0x12eda4 bound to port 46673</div><div>    TCP 0x12eda4 timer fired in SYN_SENT for 609cb55e..609cb55e 00000000</div><div>    TCP 0x12eda4 TX 46673->80 609cb55e..609cb55f           00000000    0 SYN</div><div>    IPv4 TX 10.146.0.10->10.146.0.2 len 64 proto 6 id 0100 csum 6489</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x12ef90 on vq 1</div><div>    VIRTIO-NET 0xee704 tx complete iobuf 0x12ef90</div><div>    VIRTIO-NET 0xee704 rx complete iobuf 0x12f5f4 len 74</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x1335f4 on vq 0</div><div>    IPv4 RX 10.146.0.10<-10.146.0.2 len 60 proto 6 id 0000 csum 258d</div><div>    TCP 0x12eda4 RX 46673<-80           609cb55f 5ae4dacb..5ae4dacc    0 SYN ACK</div><div>    TCP 0x12eda4 using timestamps, SACK, TX window x128, RX window x512</div><div>    TCP 0x12eda4 transitioned from SYN_SENT to ESTABLISHED</div><div>    TCP 0x12eda4 TX 46673->80 609cb55f..609cb5c1           5ae4dacc   98 PSH ACK</div><div>    IPv4 TX 10.146.0.10->10.146.0.2 len 150 proto 6 id 0201 csum 6332</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x12ec94 on vq 1</div><div>    VIRTIO-NET 0xee704 tx complete iobuf 0x12ec94</div><div>    VIRTIO-NET 0xee704 rx complete iobuf 0x12fdf4 len 74</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x12f5f4 on vq 0</div><div>    IPv4 RX 10.146.0.10<-10.146.0.2 len 60 proto 6 id 0000 csum 258d</div><div>    TCP 0x12eda4 RX 46673<-80           609cb55f 5ae4dacb..5ae4dacc    0 SYN ACK</div><div>    TCP 0x12eda4 timer fired in ESTABLISHED for 609cb55f..609cb5c1 5ae4dacc</div><div>    TCP 0x12eda4 TX 46673->80 609cb55f..609cb5c1           5ae4dacc   98 PSH ACK</div><div>    IPv4 TX 10.146.0.10->10.146.0.2 len 150 proto 6 id 0302 csum 6231</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x12ec94 on vq 1</div><div>    VIRTIO-NET 0xee704 tx complete iobuf 0x12ec94</div><div>    .TCP 0x12eda4 timer fired in ESTABLISHED for 609cb55f..609cb5c1 5ae4dacc</div><div>    TCP 0x12eda4 TX 46673->80 609cb55f..609cb5c1           5ae4dacc   98 PSH ACK</div><div>    IPv4 TX 10.146.0.10->10.146.0.2 len 150 proto 6 id 0402 csum 6131</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x12ec94 on vq 1</div><div>    VIRTIO-NET 0xee704 tx complete iobuf 0x12ec94</div><div>    VIRTIO-NET 0xee704 rx complete iobuf 0x1305f4 len 74</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x12fdf4 on vq 0</div><div>    IPv4 RX 10.146.0.10<-10.146.0.2 len 60 proto 6 id 0000 csum 258d</div><div>    TCP 0x12eda4 RX 46673<-80           609cb55f 5ae4dacb..5ae4dacc    0 SYN ACK</div><div>    ..TCP 0x12eda4 timer fired in ESTABLISHED for 609cb55f..609cb5c1 5ae4dacc</div><div>    TCP 0x12eda4 TX 46673->80 609cb55f..609cb5c1           5ae4dacc   98 PSH ACK</div><div>    IPv4 TX 10.146.0.10->10.146.0.2 len 150 proto 6 id 0503 csum 6030</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x12ec94 on vq 1</div><div>    VIRTIO-NET 0xee704 tx complete iobuf 0x12ec94</div><div>    ..VIRTIO-NET 0xee704 rx complete iobuf 0x130df4 len 74</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x1305f4 on vq 0</div><div>    IPv4 RX 10.146.0.10<-10.146.0.2 len 60 proto 6 id 0000 csum 258d</div><div>    TCP 0x12eda4 RX 46673<-80           609cb55f 5ae4dacb..5ae4dacc    0 SYN ACK</div><div>    .TCP 0x12eda4 timer fired in ESTABLISHED for 609cb55f..609cb5c1 5ae4dacc</div><div>    TCP 0x12eda4 TX 46673->80 609cb55f..609cb5c1           5ae4dacc   98 PSH ACK</div><div>    IPv4 TX 10.146.0.10->10.146.0.2 len 150 proto 6 id 0604 csum 5f2f</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x12ec94 on vq 1</div><div>    VIRTIO-NET 0xee704 tx complete iobuf 0x12ec94</div><div>    ......TCP 0x12eda4 timer expired in ESTABLISHED for 609cb55f..609cb5c1 5ae4dacc</div><div>    TCP 0x12eda4 transitioned from ESTABLISHED to CLOSED</div><div>    TCP 0x12eda4 connection deleted</div><div>     Connection timed out (<a href="http://ipxe.org/4c0a6035">http://ipxe.org/4c0a6035</a>)</div><div>    iPXE> VIRTIO-NET 0xee704 rx complete iobuf 0x1315f4 len 74</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x130df4 on vq 0</div><div>    IPv4 RX 10.146.0.10<-10.146.0.2 len 60 proto 6 id 0000 csum 258d</div><div>    TCP 0x0 RX 46673<-80           609cb55f 5ae4dacb..5ae4dacc    0 SYN ACK</div><div>    IPv4 received packet rejected by stack: The socket is not connected (<a href="http://ipxe.org/380a6001">http://ipxe.org/380a6001</a>)</div><div>    </div><div>    iPXE> VIRTIO-NET 0xee704 rx complete iobuf 0x131df4 len 74</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x1315f4 on vq 0</div><div>    IPv4 RX 10.146.0.10<-10.146.0.2 len 60 proto 6 id 0000 csum 258d</div><div>    TCP 0x0 RX 46673<-80           609cb55f 5ae4dacb..5ae4dacc    0 SYN ACK</div><div>    IPv4 received packet rejected by stack: The socket is not connected (<a href="http://ipxe.org/380a6001">http://ipxe.org/380a6001</a>)</div><div>    VIRTIO-NET 0xee704 rx complete iobuf 0x1325f4 len 42</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x131df4 on vq 0</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x1325f4 on vq 1</div><div>    VIRTIO-NET 0xee704 tx complete iobuf 0x1325f4</div><div>    VIRTIO-NET 0xee704 rx complete iobuf 0x132df4 len 62</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x1325f4 on vq 0</div><div>    IPv4 RX 10.146.0.10<-221.204.224.56 len 48 proto 6 id 6aac csum 167b</div><div>    TCP 0x0 RX 22<-2281           0a4bb0cf 3368312b..3368312c    0 SYN</div><div>    IPv4 received packet rejected by stack: The socket is not connected (<a href="http://ipxe.org/380a6001">http://ipxe.org/380a6001</a>)</div><div>    VIRTIO-NET 0xee704 rx complete iobuf 0x1335f4 len 42</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x132df4 on vq 0</div><div>    VIRTIO-NET 0xee704 enqueuing iobuf 0x1335f4 on vq 1</div><div>    VIRTIO-NET 0xee704 tx complete iobuf 0x1335f4</div><div>    </div><div><br></div><div><br></div><div>=== HTTP server 10.146.0.2 (ws01) ===</div><div><br></div><div>    $ sudo tcpdump host 10.146.0.10</div><div>    tcpdump: verbose output suppressed, use -v or -vv for full protocol decode</div><div>    listening on ens4, link-type EN10MB (Ethernet), capture size 262144 bytes</div><div>    04:55:43.715483 IP ipxe01.c.suda-main.internal.46673 > ws01.c.suda-main.internal.http: Flags [S], seq 1620882782, win 65532, options [nop,nop,TS val 323011 ecr 0,nop,nop,sackOK,nop,wscale 9,mss 1460], length 0</div><div>    04:55:43.715549 IP ws01.c.suda-main.internal.http > ipxe01.c.suda-main.internal.46673: Flags [S.], seq 1524947659, ack 1620882783, win 28160, options [mss 1420,sackOK,TS val 77061640 ecr 323011,nop,wscale 7], length 0</div><div>    04:55:44.712811 IP ws01.c.suda-main.internal.http > ipxe01.c.suda-main.internal.46673: Flags [S.], seq 1524947659, ack 1620882783, win 28160, options [mss 1420,sackOK,TS val 77061890 ecr 323011,nop,wscale 7], length 0</div><div>    04:55:46.712829 IP ws01.c.suda-main.internal.http > ipxe01.c.suda-main.internal.46673: Flags [S.], seq 1524947659, ack 1620882783, win 28160, options [mss 1420,sackOK,TS val 77062390 ecr 323011,nop,wscale 7], length 0</div><div>    04:55:50.712864 IP ws01.c.suda-main.internal.http > ipxe01.c.suda-main.internal.46673: Flags [S.], seq 1524947659, ack 1620882783, win 28160, options [mss 1420,sackOK,TS val 77063390 ecr 323011,nop,wscale 7], length 0</div><div>    04:55:58.712842 IP ws01.c.suda-main.internal.http > ipxe01.c.suda-main.internal.46673: Flags [S.], seq 1524947659, ack 1620882783, win 28160, options [mss 1420,sackOK,TS val 77065390 ecr 323011,nop,wscale 7], length 0</div><div>    04:56:14.712836 IP ws01.c.suda-main.internal.http > ipxe01.c.suda-main.internal.46673: Flags [S.], seq 1524947659, ack 1620882783, win 28160, options [mss 1420,sackOK,TS val 77069390 ecr 323011,nop,wscale 7], length 0</div><div><br></div></div><div class="gmail_extra"><br><div class="gmail_quote">2016-12-14 18:17 GMT+09:00 Ladi Prosek <span dir="ltr"><<a href="mailto:lprosek@redhat.com" target="_blank">lprosek@redhat.com</a>></span>:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Hi Akihiro,<br>
<span class=""><br>
On Wed, Dec 14, 2016 at 8:51 AM, Akihiro Suda <<a href="mailto:suda.kyoto@gmail.com">suda.kyoto@gmail.com</a>> wrote:<br>
> Hi Christian,<br>
><br>
> Thank you for the suggestion, I'll try to report this to google.<br>
><br>
> I found that the cause of this issue is because GCE's VIRTIO_PCI_QUEUE_NUM<br>
> is 4096, which is larger than iPXE's MAX_QUEUE_NUM (256).<br>
><br>
> <a href="https://git.ipxe.org/ipxe.git/blob/26050fd4c87c50503d5bd573b2ec91703676e211:/src/drivers/bus/virtio-pci.c#l43" rel="noreferrer" target="_blank">https://git.ipxe.org/ipxe.git/<wbr>blob/<wbr>26050fd4c87c50503d5bd573b2ec91<wbr>703676e211:/src/drivers/bus/<wbr>virtio-pci.c#l43</a><br>
> <a href="https://git.ipxe.org/ipxe.git/blob/26050fd4c87c50503d5bd573b2ec91703676e211:/src/include/ipxe/virtio-ring.h#l24" rel="noreferrer" target="_blank">https://git.ipxe.org/ipxe.git/<wbr>blob/<wbr>26050fd4c87c50503d5bd573b2ec91<wbr>703676e211:/src/include/ipxe/<wbr>virtio-ring.h#l24</a><br>
><br>
><br>
> IIUC this issue will be resolved if GCE supports virtio 1.0, which would<br>
> allow iPXE to use custom queue num smaller than the virtio device's max<br>
> value.<br>
<br>
</span>iPXE virtio 1.0 code does not cap the queue size to MAX_QUEUE_NUM. In<br>
fact, it does not check it against any maximum and still uses<br>
fixed-sized virtqueue data structures, just like legacy. This is a<br>
bug.<br>
<span class=""><br>
> However, it would be great if iPXE can support setting MAX_QUEUE_NUM to 4096<br>
> (via `config/general.h`, probably).<br>
<br>
</span>Even better, iPXE should try to use the host provided size in legacy<br>
mode, i.e. no MAX_QUEUE_NUM needed. The few extra dynamic allocations<br>
shouldn't hurt anything.<br>
<span class=""><br>
> Actually I tried to set MAX_QUEUE_NUM to 4096 and got virtnet_open_legacy()<br>
> succeeded, but it still doesn't work:<br>
><br>
>     iPXE> dhcp<br>
>     DHCP 0x120e44 entering discovery state<br>
>     Configuring (net0 42:01:0a:92:00:0a)...DHCP 0x120e44 DHCPDISCOVER<br>
>     DHCP 0x120e44 DHCPOFFER from <a href="http://169.254.169.254:67" rel="noreferrer" target="_blank">169.254.169.254:67</a> for 10.146.0.10<br>
>     .DHCP 0x120e44 DHCPDISCOVER<br>
>     ..DHCP 0x120e44 entering request state<br>
>     DHCP 0x120e44 DHCPREQUEST to <a href="http://169.254.169.254:67" rel="noreferrer" target="_blank">169.254.169.254:67</a> for 10.146.0.10<br>
>     DHCP 0x120e44 DHCPREQUEST to <a href="http://169.254.169.254:67" rel="noreferrer" target="_blank">169.254.169.254:67</a> for 10.146.0.10<br>
>     .DHCP 0x120e44 DHCPREQUEST to <a href="http://169.254.169.254:67" rel="noreferrer" target="_blank">169.254.169.254:67</a> for 10.146.0.10<br>
>     .DHCP 0x120e44 DHCPREQUEST to <a href="http://169.254.169.254:67" rel="noreferrer" target="_blank">169.254.169.254:67</a> for 10.146.0.10<br>
>     ...DHCP 0x120e44 DHCPREQUEST to <a href="http://169.254.169.254:67" rel="noreferrer" target="_blank">169.254.169.254:67</a> for 10.146.0.10<br>
>     ....... No configuration methods succeeded (<a href="http://ipxe.org/040ee119" rel="noreferrer" target="_blank">http://ipxe.org/040ee119</a>)<br>
>     iPXE><br>
><br>
> I haven't captured DHCP packets (because I'm unsure how to do so in GCE's<br>
> fully managed DHCP server), but I guess DHCPACK is actually sent from the<br>
> DHCP server but somehow iPXE missed it.<br>
<br>
</span>Do you see any interesting log output with DEBUG=virtio-net,virtio-pci ?<br>
<span class=""><br>
> I'd appreciate if anyone can support me to set MAX_QUEUE_NUM to 4096.<br>
<br>
</span>I'll look into it. My proposal is to keep using 128 as the cap in<br>
virtio 1.0 and support any queue size in legacy, only subject to<br>
available memory.<br>
<div class="HOEnZb"><div class="h5"><br>
> 2016-12-14 16:19 GMT+09:00 Christian Nilsson <<a href="mailto:nikize@gmail.com">nikize@gmail.com</a>>:<br>
>><br>
>> You might want to report this to google as well if you haven't already.<br>
>><br>
>> On Wed, Dec 14, 2016 at 7:16 AM, Akihiro Suda <<a href="mailto:suda.kyoto@gmail.com">suda.kyoto@gmail.com</a>><br>
>> wrote:<br>
>> > Hello,<br>
>> ><br>
>> > I tried to boot iPXE on a Google Compute Engine instance, but the virtio<br>
>> > driver doesn't work because virtnet_open_legacy() fails to find<br>
>> > virtqueues.<br>
>> ><br>
>> > Please let me know what I can do for providing further information to<br>
>> > debug<br>
>> > the issue.<br>
>> ><br>
>> > The serial console output with "DEBUG=virtio-net" is as follows:<br>
>> ><br>
>> >     iPXE initialising devices...Common virtio capability not found!<br>
>> >     VIRTIO-NET 0xdf584 busaddr=0000:00:04.0 ioaddr=0xc040 irq=11<br>
>> >     VIRTIO-NET 0xdf584 mac=42:01:0a:92:00:0a<br>
>> >     ok<br>
>> ><br>
>> >     iPXE 1.0.0+ (26050) -- Open Source Network Boot Firmware --<br>
>> > <a href="http://ipxe.org" rel="noreferrer" target="_blank">http://ipxe.org</a><br>
>> >     Features: DNS HTTP iSCSI TFTP SRP AoE ELF MBOOT PXE bzImage Menu<br>
>> > PXEXT<br>
>> >     iPXE> ifstat<br>
>> >     net0: 42:01:0a:92:00:0a using virtio-net on 0000:00:04.0 (closed)<br>
>> >       [Link:up, TX:0 TXE:0 RX:0 RXE:0]<br>
>> >     iPXE> dhcp<br>
>> >     VIRTIO-NET 0xdf584 cannot register queue 0<br>
>> >     Could not open net0: No such file or directory<br>
>> > (<a href="http://ipxe.org/2d5c403b" rel="noreferrer" target="_blank">http://ipxe.org/2d5c403b</a>)<br>
>> >     iPXE><br>
>> ><br>
>> ><br>
>> > This ENOENT is raised from virtnet_open_legacy():<br>
>> ><br>
>> > <a href="https://git.ipxe.org/ipxe.git/blob/26050fd4c87c50503d5bd573b2ec91703676e211:/src/drivers/net/virtio-net.c#l205" rel="noreferrer" target="_blank">https://git.ipxe.org/ipxe.git/<wbr>blob/<wbr>26050fd4c87c50503d5bd573b2ec91<wbr>703676e211:/src/drivers/net/<wbr>virtio-net.c#l205</a><br>
>> ><br>
>> ><br>
>> > I also tested some previous commits, but all of them failed, so the<br>
>> > issue is<br>
>> > not a regression in some recent commit:<br>
>> ><br>
>> >  * 26050fd (Dec  8, 2016): the last commit when I tested<br>
>> >  * 7b499f8 (Apr 11, 2016): the last commit without support for virtio<br>
>> > 1.0<br>
>> >  * e4419ff (Jul  2, 2010):  the first commit with the "native iPXE<br>
>> > driver"<br>
>> > (The commit date is older than 232c208, but actually newer than 232c208)<br>
>> >  * 232c208 (Jul 11, 2010): the last commit without the "native iPXE<br>
>> > driver".<br>
>> > The error message is "ERROR: queue size 4096 > 512", "Cannot register<br>
>> > queue<br>
>> > #0"<br>
>> ><br>
>> ><br>
>> > Regards,<br>
>> ><br>
>> > Akihiro Suda<br>
>> ><br>
>> ><br>
>> > ______________________________<wbr>_________________<br>
>> > ipxe-devel mailing list<br>
>> > <a href="mailto:ipxe-devel@lists.ipxe.org">ipxe-devel@lists.ipxe.org</a><br>
>> > <a href="https://lists.ipxe.org/mailman/listinfo.cgi/ipxe-devel" rel="noreferrer" target="_blank">https://lists.ipxe.org/<wbr>mailman/listinfo.cgi/ipxe-<wbr>devel</a><br>
>> ><br>
><br>
><br>
><br>
> ______________________________<wbr>_________________<br>
> ipxe-devel mailing list<br>
> <a href="mailto:ipxe-devel@lists.ipxe.org">ipxe-devel@lists.ipxe.org</a><br>
> <a href="https://lists.ipxe.org/mailman/listinfo.cgi/ipxe-devel" rel="noreferrer" target="_blank">https://lists.ipxe.org/<wbr>mailman/listinfo.cgi/ipxe-<wbr>devel</a><br>
><br>
</div></div></blockquote></div><br></div>