On 4/11/21 2:43 PM, Eric Dumazet wrote:
> On Sun, Apr 11, 2021 at 11:32 PM Guenter Roeck <linux@xxxxxxxxxxxx> wrote:
>>
>> On 4/11/21 2:23 PM, Eric Dumazet wrote:
>>> On Sun, Apr 11, 2021 at 10:37 PM Guenter Roeck <linux@xxxxxxxxxxxx> wrote:
>>>>
>>>> On 4/11/21 8:06 AM, Eric Dumazet wrote:
>>>>> On Sun, Apr 11, 2021 at 3:43 PM Guenter Roeck <linux@xxxxxxxxxxxx> wrote:
>>>>>
>>>>>> This patch causes a virtio-net interface failure when booting sh4 images
>>>>>> in qemu. The test case is nothing special: Just try to get an IP address
>>>>>> using udhcpc. If it fails, udhcpc reports:
>>>>>>
>>>>>> udhcpc: started, v1.33.0
>>>>>> udhcpc: sending discover
>>>>>> FAIL
>>>>>>
>>>>>
>>>>> Can you investigate where the incoming packet is dropped ?
>>>>>
>>>>
>>>> Unless I am missing something, packets are not dropped. It looks more
>>>> like udhcpc gets bad indigestion in the receive path and exits immediately.
>>>> Plus, it doesn't happen all the time; sometimes it receives the discover
>>>> response and is able to obtain an IP address.
>>>>
>>>> Overall this is quite puzzling since udhcpc exits immediately when the problem
>>>> is seen, no matter which option I give it on the command line; it should not
>>>> really do that.
>>>
>>>
>>> Could you strace both cases and report differences you can spot ?
>>>
>>> strace -o STRACE -f -s 1000 udhcpc
>>>
>>
>> I'll give it a try. It will take a while; I'll need to add strace to my root
>> file systems first.
>>
>> As a quick hack, I added some debugging into the kernel; it looks like
>> the data part of the dhcp discover response may get lost with your patch
>> in place.
>
> Data is not lost, the payload is whole contained in skb frags, which
> was expected from my patch.
>
> Maybe this sh arch does something wrong in this case.
>
> This could be checksuming...
>
> Please check
>
> nstat -n
> <run udhcpc>
> nstat
>
Does that tell you anything ?
/ # nstat -n
/ # udhcpc -n -q
udhcpc: started, v1.33.0
udhcpc: sending discover
/ # nstat
#kernel
IpInReceives 1 0.0
IpInDelivers 1 0.0
UdpIgnoredMulti 1 0.0
IpExtInBcastPkts 1 0.0
IpExtInOctets 576 0.0
IpExtInBcastOctets 576 0.0
IpExtInNoECTPkts 1 0.0
Also, one interesting detail is that the problem is not seen all the time,
even with your patch in place. Not sure if I mentioned that before. strace
output in the success case (same image, with patch in place) looks as follows.
130 write(2, "udhcpc: sending discover\n", 25) = 25
130 socket(AF_PACKET, SOCK_DGRAM, htons(ETH_P_IP)) = 6
130 bind(6, {sa_family=AF_PACKET, sll_protocol=htons(ETH_P_IP), sll_ifindex=if_nametoindex("eth0"), sll_hatype=ARPHRD_NETROM, sll_pkttype=PACKET_HOST, sll_halen=6, sll_addr=[0xff, 0xff, 0xff, 0xf
130 sendto(6, "E\0\1H\0\0\0\0@\21y\246\0\0\0\0\377\377\377\377\0D\0C\0014\227r\1\1\6\0\5\16\36P\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0RT\0\0224V\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0
130 close(6) = 0
130 fcntl64(5, F_SETFD, FD_CLOEXEC) = 0
130 clock_gettime64(CLOCK_MONOTONIC, {tv_sec=25, tv_nsec=202168729}) = 0
130 poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, 3000) = 1 ([{fd=5, revents=POLLIN}])
130 read(3, 0x7bf47a73, 1) = -1 EAGAIN (Resource temporarily unavailable)
130 recvmsg(5, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="E\20\2@\0\10\0\0@\21l\224\n\0\2\2\377\377\377\377\0C\0D\2,\230\23\2\1\6\0\5\16\36P\0\0\0\0\0\0\0\0\n\0\2\17\n\0\2\2\0\0\0\0RT\0\0
130 clock_gettime64(CLOCK_MONOTONIC, {tv_sec=25, tv_nsec=205504062}) = 0
130 fcntl64(5, F_SETFD, FD_CLOEXEC) = 0
130 socket(AF_INET, SOCK_RAW, IPPROTO_RAW) = 6
130 ioctl(6, SIOCGIFINDEX, {ifr_name="eth0", }) = 0
130 ioctl(6, SIOCGIFHWADDR, {ifr_name="eth0", ifr_hwaddr={sa_family=ARPHRD_ETHER, sa_data=52:54:00:12:34:56}}) = 0
130 close(6) = 0
130 clock_gettime64(CLOCK_MONOTONIC, {tv_sec=25, tv_nsec=208676862}) = 0
130 write(2, "udhcpc: sending select for 10.0.2.15\n", 37) = 37
130 socket(AF_PACKET, SOCK_DGRAM, htons(ETH_P_IP)) = 6
130 bind(6, {sa_family=AF_PACKET, sll_protocol=htons(ETH_P_IP), sll_ifindex=if_nametoindex("eth0"), sll_hatype=ARPHRD_NETROM, sll_pkttype=PACKET_HOST, sll_halen=6, sll_addr=[0xff, 0xff, 0xff, 0xf
130 sendto(6, "E\0\1H\0\0\0\0@\21y\246\0\0\0\0\377\377\377\377\0D\0C\0014\25Y\1\1\6\0\5\16\36P\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0RT\0\0224V\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\
130 close(6) = 0
130 fcntl64(5, F_SETFD, FD_CLOEXEC) = 0
130 clock_gettime64(CLOCK_MONOTONIC, {tv_sec=25, tv_nsec=213060729}) = 0
130 poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, 3000) = 1 ([{fd=5, revents=POLLIN}])
130 read(3, 0x7bf47a73, 1) = -1 EAGAIN (Resource temporarily unavailable)
130 recvmsg(5, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="E\20\2@\0\t\0\0@\21l\223\n\0\2\2\377\377\377\377\0C\0D\2,\225\23\2\1\6\0\5\16\36P\0\0\0\0\0\0\0\0\n\0\2\17\n\0\2\2\0\0\0\0RT\0\02
130 clock_gettime64(CLOCK_MONOTONIC, {tv_sec=25, tv_nsec=215453662}) = 0
130 write(2, "udhcpc: lease of 10.0.2.15 obtained, lease time 86400\n", 54) = 54
In that case, the output of nstat is as follows.
/ # nstat
#kernel
IpInReceives 2 0.0
IpInDelivers 2 0.0
UdpIgnoredMulti 2 0.0
IpExtInBcastPkts 2 0.0
IpExtInOctets 1152 0.0
IpExtInBcastOctets 1152 0.0
IpExtInNoECTPkts 2 0.0
Guenter
_______________________________________________
Virtualization mailing list
Virtualization@xxxxxxxxxxxxxxxxxxxxxxxxxx
https://lists.linuxfoundation.org/mailman/listinfo/virtualization
