NetBSD-Bugs archive
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]
bin/59636: Lots of getsockname log spam from blocklistd
>Number: 59636
>Category: bin
>Synopsis: Lots of getsockname log spam from blocklistd
>Confidential: no
>Severity: serious
>Priority: medium
>Responsible: bin-bug-people
>State: open
>Class: sw-bug
>Submitter-Id: net
>Arrival-Date: Sun Sep 07 01:40:00 +0000 2025
>Originator: Hisashi T Fujinaka
>Release: NetBSD 11.0_BETA
>Organization:
>Environment:
NetBSD mail.i8u.org 11.0_BETA NetBSD 11.0_BETA (MARA) #3486: Fri Aug 29 15:06:25 PDT 2025 htodd%mail.i8u.org@localhost:/usr/obj/amd64/sys/arch/amd64/compile/MARA amd64
>Description:
Twice a minute, sshd caused blocklistd to generate log messages like:
Sep 5 19:30:58 mail blocklistd[1071]: unconnected socket with no peer in message
Sep 5 19:31:28 mail blocklistd[1071]: processing type=1 fd=6 remote=192.168.11.1:50552 msg=ssh uid=0 gid=0
Sep 5 19:31:28 mail blocklistd[1071]: getsockname failed (Invalid argument)
Using ktrace, Riastradh@ had a look and said the following in irc:
(18:20) < Riastradh> 9213 9213 sshd-session 1757034027.975948004 CALL sendmsg(8,0x7f7fff842190,0) (18:21) < Riastradh>
9213 9213 sshd-session 1757034027.975949112 MISC msghdr: [name=0x0, namelen=0, iov=0x7f7fff842160,
iovlen=1, control=0x7f7fff842170, controllen=24, flags=4000000]
(18:21) < Riastradh> 9213 9213 sshd-session 1757034027.975950657 MISC mbcontrol: [len=20, level=65535, type=1]
(18:21) < Riastradh> is the pfilter_notify -> blocklist_r call that sends the fd to blocklistd
(18:21) < Riastradh> 1071 1071 blocklistd 1757034027.975979446 CALL recvmsg(3,0x7f7fff9cf550,0)
(18:21) < Riastradh> 1071 1071 blocklistd 1757034027.975980897 MISC msghdr: [name=0x0, namelen=0, iov=0x7f7fff9cf540,
iovlen=1, control=0x7f7fff9cf580, controllen=128, flags=4000000]
(18:21) < Riastradh> 1071 1071 blocklistd 1757034027.975988685 MISC mbcontrol: [len=20, level=65535, type=1]
(18:21) < Riastradh> is where blocklistd receives the fd
(18:22) < Riastradh> then
(18:22) < Riastradh> 1071 1071 blocklistd 1757034027.976076234 CALL getsockname(6,0x7f7fff9cf790,0x7f7fff9cf814)
(18:22) < Riastradh> 1071 1071 blocklistd 1757034027.976077623 RET getsockname -1 errno 22 Invalid argument
(18:22) < Riastradh> and shortly after
(18:22) < Riastradh> 9213 9213 sshd-session 1757034027.976481806 CALL exit(0xff)
(18:23) < Riastradh> So that's actually pretty puzzling -- getsockname fails while sshd-session is still running and hasn't
closed
or shutdown the fd!
(18:23) < Riastradh> (I believe I put all those records in chronological order.)
(18:25) < htodd> huh
(18:26) < Riastradh> fd_getsock never fails with EINVAL
(18:26) < Riastradh> (EBADF or ENOTSOCK, but not EINVAL)
(18:26) < Riastradh> and I don't think copyin or copyout fail with EINVAL
(18:27) < Riastradh> so that narrows it down to
(18:27) < Riastradh> error = (*so->so_proto->pr_usrreqs->pr_sockaddr)(so, nam);
(18:27) < Riastradh> for which the thing is presumably
(18:27) < Riastradh> netinet/tcp_usrreq.c: .pr_sockaddr = tcp_sockaddr,
(18:27) < Riastradh> oh
(18:27) < Riastradh> duh
(18:27) < Riastradh> the _other_ side shut down the socket
(18:28) < Riastradh> inp = sotoinpcb(so);
(18:28) < Riastradh> if (inp == NULL)
(18:28) < Riastradh> return EINVAL;
(18:28) < Riastradh> The interaction with sshd-session was this:
(18:28) < Riastradh> 9213 9213 sshd-session 1757034027.975891847 CALL write(7,0x705ec590cc00,0x40)
(18:28) < Riastradh> 9213 9213 sshd-session 1757034027.975907115 GIO fd 7 wrote 64 bytes
(18:28) < Riastradh> "SSH-2.0-OpenSSH_10.0 NetBSD_Secure_Shell-20250409-hpn13v14-lpk\r\n"
(18:28) < Riastradh> 9213 9213 sshd-session 1757034027.975908316 RET write 64/0x40
(18:28) < Riastradh> 9213 9213 sshd-session 1757034027.975920735 CALL read(7,0x7f7fff8423d7,1)
(18:28) < Riastradh> That is, sshd-session wrote the banner, and then the remote side hung up, so read returned 0 (eof).
(18:28) < Riastradh> 9213 9213 sshd-session 1757034027.975921939 GIO fd 7 read 0 bytes
(18:28) < Riastradh> ""
(18:29) < Riastradh> fvc70r: so blocklistd fundamentally doesn't work for this use-case
(18:29) < Riastradh> fvc70r: not if you insist on verifying getsockname in blocklistd itself
(18:29) < Riastradh> mystery solved
>How-To-Repeat:
It repeats twice a minute for me.
>Fix:
Home |
Main Index |
Thread Index |
Old Index