Re: s390 EAGAIN on send{msg,to}()/recvmsg() on small MTU and big packet size

[Petr Vorel]

Hi,

[ Cc Alexey and Ihno ]

Any hint on this? I know it's a corner case, but it'd be nice to have it fixed.

Kind regards,
Petr

> Hi,

> I've found a bug on s390 on small MTU combined with big packet size, using ping
> (of course both within valid ranges, e.g. MTU 552 and packet size 61245).

> Below is full reproducer on netns.

> I tested it on vanilla: v5.3-rc8 and v4.16.
> I reproduced it on current iputils master which uses sendto()/recvmsg() and on
> older version which uses sendmsg()/recvmsg().

> As I'm not aware of any s390 specific socket code in kernel I suspect big endian or something else.

> This bug was find with LTP/if-mtu-change.sh.

> REPRODUCER:
> LTP_NS="ip netns exec ltp_ns"
> ip net add ltp_ns
> ip li add name ltp_ns_veth1 type veth peer name ltp_ns_veth2
> ip li set dev ltp_ns_veth1 netns ltp_ns
> $LTP_NS ip li set lo up

> ip xfrm policy flush
> ip xfrm state flush
> ip link set ltp_ns_veth2 down
> ip route flush dev ltp_ns_veth2
> ip addr flush dev ltp_ns_veth2
> ip link set ltp_ns_veth2 up
> ip addr add 10.0.0.2/24 dev ltp_ns_veth2

> $LTP_NS ip xfrm policy flush
> $LTP_NS ip xfrm state flush
> $LTP_NS ip link set ltp_ns_veth1 down
> $LTP_NS ip route flush dev ltp_ns_veth1
> $LTP_NS ip addr flush dev ltp_ns_veth1
> $LTP_NS ip link set ltp_ns_veth1 up
> $LTP_NS ip addr add 10.0.0.1/24 dev ltp_ns_veth1

> i=552; ip link set dev ltp_ns_veth2 mtu $i; $LTP_NS ip link set dev ltp_ns_veth1 mtu $i # it's enough to set just one of them

> ping -I 10.0.0.2 -c 1 10.0.0.1 -s 61245 # fail
> ping -I 10.0.0.2 -c 1 10.0.0.1 -s 61244 # ok

> FAIL (iputils-s20121221 from package, using sendmsg())
> ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) = 0
> ioctl(1, TIOCGWINSZ, {ws_row=74, ws_col=273, ws_xpixel=1911, ws_ypixel=1050}) = 0
> sendmsg(3, {msg_name(16)={sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("10.0.0.1")}, msg_iov(1)=[{"\10\0\253_\241\373\0\1\0\0\0\0]wf\330\0\0\0\0\0\6\375\201\20\21\22\23\24\25\26\27"..., 61253}], msg_controllen=0, msg_flags=0}, 0) = 61253
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={10, 0}}, NULL) = 0
> recvmsg(3, 0x3fff887b588, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3fff887b588, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3fff887b588, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3fff887b588, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3fff887b588, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3fff887b588, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3fff887b588, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3fff887b588, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3fff887b588, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3fff887b588, 0)            = -1 EINTR (Interrupted system call)
> --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
> sigreturn({mask=[]})                    = -1 EINTR (Interrupted system call)

> OK (iputils-s20121221 from package, using sendmsg())
> ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) = 0
> ioctl(1, TIOCGWINSZ, {ws_row=74, ws_col=273, ws_xpixel=1911, ws_ypixel=1050}) = 0
> sendmsg(3, {msg_name(16)={sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("10.0.0.1")}, msg_iov(1)=[{"\10\0\3u\242\266\0\1\0\0\0\0]wgd\0\0\0\0\0\6\340%\20\21\22\23\24\25\26\27"..., 61252}], msg_controllen=0, msg_flags=0}, 0) = 61252
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={10, 0}}, NULL) = 0
> recvmsg(3, {msg_name(16)={sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("10.0.0.1")}, msg_iov(1)=[{"E\0\357X2\277\0\0@\1D\343\n\0\0\1\n\0\0\2\0\0\vu\242\266\0\1\0\0\0\0"..., 61380}], msg_controllen=32, [{cmsg_len=32, cmsg_level=SOL_SOCKET, cmsg_type=0x1d /*
> SCM_??? */, ...}], msg_flags=0}, 0) = 61272
> write(1, "61252 bytes from 10.0.0.1: icmp_"..., 5961252 bytes from 10.0.0.1: icmp_seq=1 ttl=64 time=0.442 ms
> ) = 59

> FAIL (current iputils master, using sendto())
> ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) = 0
> ioctl(1, TIOCGWINSZ, {ws_row=74, ws_col=273, ws_xpixel=1911, ws_ypixel=1050}) = 0
> sendto(3, "\10\0\2=\313\315\0\1\0\0\0\0]vH;\0\0\0\0\0\7\233o\20\21\22\23\24\25\26\27"..., 61253, 0, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("10.0.0.1")}, 16) = 61253
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={10, 0}}, NULL) = 0
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EAGAIN (Resource temporarily unavailable)
> recvmsg(3, 0x3ffe7e7b388, 0)            = -1 EINTR (Interrupted system call)
> --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
> sigreturn({mask=[]})                    = -1 EINTR (Interrupted system call)

> OK (current iputils master, using sendto())
> ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) = 0
> ioctl(1, TIOCGWINSZ, {ws_row=74, ws_col=273, ws_xpixel=1911, ws_ypixel=1050}) = 0
> sendto(3, "\10\0y\4\313\365\0\1\0\0\0\0]vHw\0\0\0\0\0\4`G\20\21\22\23\24\25\26\27"..., 61252, 0, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("10.0.0.1")}, 16) = 61252
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={10, 0}}, NULL) = 0
> recvmsg(3, {msg_name(16)={sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("10.0.0.1")}, msg_iov(1)=[{"E\0\357Xc$\0\0@\1\24~\n\0\0\1\n\0\0\2\0\0\201\4\313\365\0\1\0\0\0\0"..., 61380}], msg_controllen=32, [{cmsg_len=32, cmsg_level=SOL_SOCKET, cmsg_type=0x1d /*
> SCM_??? */, ...}], msg_flags=0}, 0) = 61272
> write(1, "61252 bytes from 10.0.0.1: icmp_"..., 59) = 59

> Kind regards,
> Petr