Re: net.inet.udp.log_in_vain strange syslog reports
On 02/15/2017 08:56, Mark Martinec wrote: In a similar vein, I noticed also the following in our logs, with net.inet.tcp.log_in_vain=1. Looks like messages got concatenated somehow: Jan 25 01:37:53 mildred kernel: TCP: [2607:ff10:c5:509a::10]:26459 to [2001:1470:ff80::80:16]:4911 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:14898 to [2001:1470:ff80::80:16]:5222 tcpflags 0x2; tcp_input: Connection attempt to closed port The length of the truncated "TCP:...closed" message is just under 128, which is the PRINTF_BUFR_SIZE as defined in sys/amd64/conf/GENERIC. You could try increasing this value and rebuilding your kernel to see if that fixes the truncation. Don't increase it very much, since it's used to declare a buffer on the stack, and stack space is quite limited. For this case, 180 should be enough. Eric ___ freebsd-stable@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-stable To unsubscribe, send any mail to "freebsd-stable-unsubscr...@freebsd.org"
Re: net.inet.udp.log_in_vain strange syslog reports
2017-02-06 18:04, Eric van Gyzen wrote: On 02/06/2017 10:19, Mark Martinec wrote: Hope the fix finds its way into 11.1 (or better yet, as a patch level in 10.0). Should I open a bug report? It will quite likely get into 11.1. As for a 10.x patch, you would have to ask re@ (I think), but I doubt it. These messages are really just informative and can't be used for any filtering, since the source address could be spoofed. I meant to say 11.0-p*, but nevermind. In a similar vein, I noticed also the following in our logs, with net.inet.tcp.log_in_vain=1. Looks like messages got concatenated somehow: Jan 25 01:37:53 mildred kernel: TCP: [2607:ff10:c5:509a::10]:26459 to [2001:1470:ff80::80:16]:4911 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:14898 to [2001:1470:ff80::80:16]:5222 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 25 23:55:09 mildred kernel: TCP: [2607:ff10:c5:509a::10]:58022 to [2001:1470:ff80::80:16]:9981 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:34680 to [2001:1470:ff80::80:16]:10243 tcpflags 0x2; tcp_input: Connection attempt to closedport Jan 25 23:55:09 mildred kernel: TCP: [2607:ff10:c5:509a::10]:30991 to [2001:1470:ff80::80:16]:8554 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:20012 to [2001:1470:ff80::80:16]:8443 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 25 23:55:09 mildred kernel: TCP: [2607:ff10:c5:509a::10]:14166 to [2001:1470:ff80::80:16]: tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:34680 to [2001:1470:ff80::80:16]:8010 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 25 23:55:09 mildred kernel: TCP: [2607:ff10:c5:509a::10]:47957 to [2001:1470:ff80::80:16]:3460 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:34680 to [2001:1470:ff80::80:16]:13579 tcpflags 0x2; tcp_input: Connection attempt to closedport Jan 25 23:55:09 mildred kernel: TCP: [2607:ff10:c5:509a::10]:20012 to [2001:1470:ff80::80:16]:9001 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:30651 to [2001:1470:ff80::80:16]:9000 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 12 04:50:58 mildred kernel: TCP: [2607:ff10:c5:509a::1]:42266 to [2001:1470:ff80::80:16]:49153 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::1]:35372 to [2001:1470:ff80::80:16]:62078 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 18 03:01:59 mildred kernel: TCP: [2607:ff10:c5:509a::10]:58022 to [2001:1470:ff80::80:16]:9200 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:46640 to [2001:1470:ff80::80:16]:8181 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 18 03:01:59 mildred kernel: TCP: [2607:ff10:c5:509a::10]:36877 to [2001:1470:ff80::80:16]:7218 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:46640 to [2001:1470:ff80::80:16]:7071 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 18 03:01:59 mildred kernel: TCP: [2607:ff10:c5:509a::10]:30651 to [2001:1470:ff80::80:16]:9000 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:36877 to [2001:1470:ff80::80:16]:2332 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 18 03:01:59 mildred kernel: TCP: [2607:ff10:c5:509a::10]:46640 to [2001:1470:ff80::80:16]:7548 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::10]:46640 to [2001:1470:ff80::80:16]:5986 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 19 02:52:34 mildred kernel: TCP: [2607:ff10:c5:509a::1]:42266 to [2001:1470:ff80::80:16]:49153 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::1]:35372 to [2001:1470:ff80::80:16]:62078 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 19 02:52:34 mildred kernel: TCP: [2607:ff10:c5:509a::1]:61788 to [2001:1470:ff80::80:16]:2 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::1]:34680 to [2001:1470:ff80::80:16]:10243 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 19 02:52:34 mildred kernel: TCP: [2607:ff10:c5:509a::1]:41249 to [2001:1470:ff80::80:16]:44818 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::1]:49717 to [2001:1470:ff80::80:16]:8649 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 20 04:49:15 mildred kernel: TCP: [2607:ff10:c5:509a::1]:36877 to [2001:1470:ff80::143:1]:50100 tcpflags 0x2; tcp_input: Connection attempt to closed TCP: [2607:ff10:c5:509a::1]:42266 to [2001:1470:ff80::143:1]:49153 tcpflags 0x2; tcp_input: Connection attempt to closed port Jan 20 10:03:52 mildred kernel: TCP: [2607:ff10:c5:509a::10]:31430 to [2001:1470:ff80::143:1]:8099 tcpflags 0x2; tcp_input: Connection
Re: net.inet.udp.log_in_vain strange syslog reports
On 02/06/2017 10:19, Mark Martinec wrote: > > One minor nit: > instead of a hack: > > char src[4*sizeof "123"]; > char dst[4*sizeof "123"]; > > it would be cleaner and in sync with the equivalent code in > sys/netinet6/udp6_usrreq.c > to use the INET_ADDRSTRLEN constant (from sys/netinet/in.h, value 16): > > char src[INET_ADDRSTRLEN]; > char dst[INET_ADDRSTRLEN]; Agreed. > Hope the fix finds its way into 11.1 (or better yet, as a patch level in > 10.0). > Should I open a bug report? It will quite likely get into 11.1. As for a 10.x patch, you would have to ask re@ (I think), but I doubt it. These messages are really just informative and can't be used for any filtering, since the source address could be spoofed. Eric ___ freebsd-stable@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-stable To unsubscribe, send any mail to "freebsd-stable-unsubscr...@freebsd.org"
Re: net.inet.udp.log_in_vain strange syslog reports
On 2017-02-02 12:55, Mark Martinec wrote: 11.0-RELEASE-p7, net.inet.udp.log_in_vain=1 The following syslog entries seem to indicate some buffer overruns in the reporting code (not all log lines are broken, just some). (the actual failed connection attempts were indeed there, it's just that the reported IP address is highly suspicious) Mark 2017-02-03 20:05, Eric van Gyzen wrote: There is no buffer overrun, so no cause for alarm. The problem is concurrent usage of a single string buffer by multiple threads. The buffer is inside inet_ntoa(), defined in sys/libkern/inet_ntoa.c. In this case, it is called from udp_input(). Would you like to test the following patch? Eric diff --git a/sys/netinet/udp_usrreq.c b/sys/netinet/udp_usrreq.c index 173c44c..ca2dda1 100644 --- a/sys/netinet/udp_usrreq.c +++ b/sys/netinet/udp_usrreq.c @@ -674,13 +674,13 @@ udp_input(struct mbuf **mp, int *offp, int proto) INPLOOKUP_RLOCKPCB, ifp, m); if (inp == NULL) { if (udp_log_in_vain) { - char buf[4*sizeof "123"]; + char src[4*sizeof "123"]; + char dst[4*sizeof "123"]; - strcpy(buf, inet_ntoa(ip->ip_dst)); log(LOG_INFO, "Connection attempt to UDP %s:%d from %s:%d\n", - buf, ntohs(uh->uh_dport), inet_ntoa(ip->ip_src), - ntohs(uh->uh_sport)); + inet_ntoa_r(ip->ip_dst, dst), ntohs(uh->uh_dport), + inet_ntoa_r(ip->ip_src, src), ntohs(uh->uh_sport)); } UDPSTAT_INC(udps_noport); if (m->m_flags & (M_BCAST | M_MCAST)) { Thanks, the explanation makes sense and the patch looks good (mind the TABs). Running it now, expecting no surprises there. One minor nit: instead of a hack: char src[4*sizeof "123"]; char dst[4*sizeof "123"]; it would be cleaner and in sync with the equivalent code in sys/netinet6/udp6_usrreq.c to use the INET_ADDRSTRLEN constant (from sys/netinet/in.h, value 16): char src[INET_ADDRSTRLEN]; char dst[INET_ADDRSTRLEN]; Hope the fix finds its way into 11.1 (or better yet, as a patch level in 10.0). Should I open a bug report? Mark ___ freebsd-stable@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-stable To unsubscribe, send any mail to "freebsd-stable-unsubscr...@freebsd.org"
Re: net.inet.udp.log_in_vain strange syslog reports
On 02/02/2017 12:55, Mark Martinec wrote: 11.0-RELEASE-p7, net.inet.udp.log_in_vain=1 The following syslog entries seem to indicate some buffer overruns in the reporting code (not all log lines are broken, just some). (the actual failed connection attempts were indeed there, it's just that the reported IP address is highly suspicious) Mark Connection attempt to UDP 193.2.4.2:53 from 95.87.1521242:26375 There is no buffer overrun, so no cause for alarm. The problem is concurrent usage of a single string buffer by multiple threads. The buffer is inside inet_ntoa(), defined in sys/libkern/inet_ntoa.c. In this case, it is called from udp_input(). Would you like to test the following patch? Eric diff --git a/sys/netinet/udp_usrreq.c b/sys/netinet/udp_usrreq.c index 173c44c..ca2dda1 100644 --- a/sys/netinet/udp_usrreq.c +++ b/sys/netinet/udp_usrreq.c @@ -674,13 +674,13 @@ udp_input(struct mbuf **mp, int *offp, int proto) INPLOOKUP_RLOCKPCB, ifp, m); if (inp == NULL) { if (udp_log_in_vain) { - char buf[4*sizeof "123"]; + char src[4*sizeof "123"]; + char dst[4*sizeof "123"]; - strcpy(buf, inet_ntoa(ip->ip_dst)); log(LOG_INFO, "Connection attempt to UDP %s:%d from %s:%d\n", - buf, ntohs(uh->uh_dport), inet_ntoa(ip->ip_src), - ntohs(uh->uh_sport)); + inet_ntoa_r(ip->ip_dst, dst), ntohs(uh->uh_dport), + inet_ntoa_r(ip->ip_src, src), ntohs(uh->uh_sport)); } UDPSTAT_INC(udps_noport); if (m->m_flags & (M_BCAST | M_MCAST)) { ___ freebsd-stable@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-stable To unsubscribe, send any mail to "freebsd-stable-unsubscr...@freebsd.org"
net.inet.udp.log_in_vain strange syslog reports
11.0-RELEASE-p7, net.inet.udp.log_in_vain=1 The following syslog entries seem to indicate some buffer overruns in the reporting code (not all log lines are broken, just some). (the actual failed connection attempts were indeed there, it's just that the reported IP address is highly suspicious) Mark Connection attempt to UDP 193.2.4.2:53 from 95.87.1521242:26375 Connection attempt to UDP 193.2.4.2:53 from 95.87.1521242:55806 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:54530 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:55504 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:54530 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:49526 Connection attempt to UDP 193.2.4.2:53 from 95.8231520242:56838 Connection attempt to UDP 193.2.4.2:53 from 95.8231520242:32768 Connection attempt to UDP 193.2.4.2:53 from 95.8241523242:5387 Connection attempt to UDP 193.2.4.2:53 from 95.8241523242:54530 Connection attempt to UDP 193.2.4.2:53 from 21.823154.242:46692 Connection attempt to UDP 193.2.4.2:53 from 21.823154.242:32768 Connection attempt to UDP 193.2.4.2:53 from 19387.154.242:51931 Connection attempt to UDP 193.2.4.2:53 from 19387.154.242:59881 Connection attempt to UDP 193.2.4.2:53 from 212873154.242:53424 Connection attempt to UDP 193.2.4.2:53 from 212873154.242:53937 Connection attempt to UDP 193.2.4.2:53 from 19387.1587242:46692 Connection attempt to UDP 193.2.4.2:53 from 19387.1587242:52594 Connection attempt to UDP 193.2.4.2:53 from 19387.1587242:59639 Connection attempt to UDP 193.2.4.2:53 from 19387.1587242:50869 Connection attempt to UDP 193.2.4.2:53 from 19382.1587242:55806 Connection attempt to UDP 193.2.4.2:53 from 19382.1587242:54650 Connection attempt to UDP 193.2.4.2:53 from 95.824154.242:54322 Connection attempt to UDP 193.2.4.2:53 from 95.824154.242:49871 Connection attempt to UDP 193.2.4.2:53 from 95.824154.242:57807 Connection attempt to UDP 193.2.4.2:53 from 95.824154.242:51931 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:52930 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:50869 Connection attempt to UDP 193.2.4.2:53 from 212823152.242:56838 Connection attempt to UDP 193.2.4.2:53 from 212823152.242:32768 Connection attempt to UDP 193.2.4.2:53 from 21.8231521242:63724 Connection attempt to UDP 193.2.4.2:53 from 21.8231521242:55222 Connection attempt to UDP 193.2.4.2:53 from 1948249.230.46:52599 Connection attempt to UDP 193.2.4.2:53 from 1948249.230.46:38496 Connection attempt to UDP 193.2.4.2:53 from 2128235.209.250:43608 Connection attempt to UDP 193.2.4.2:53 from 2128235.209.250:47257 Connection attempt to UDP 193.2.4.2:53 from 19387.1594242:54324 Connection attempt to UDP 193.2.4.2:53 from 19387.1594242:34613 Connection attempt to UDP 193.2.4.2:53 from 2128235.2124180:54377 Connection attempt to UDP 193.2.4.2:53 from 2128235.2124180:50869 Connection attempt to UDP 193.2.4.2:53 from 95.87.1547242:51698 Connection attempt to UDP 193.2.4.2:53 from 95.87.1547242:55222 Connection attempt to UDP 193.2.4.2:53 from 193.2.4.2242:55222 Connection attempt to UDP 193.2.4.2:53 from 19.8241523242:38496 Connection attempt to UDP 193.2.4.2:53 from 19.8241523242:55135 Connection attempt to UDP 193.2.4.2:53 from 95.824154.242:50370 Connection attempt to UDP 193.2.4.2:53 from 95.824154.242:64533 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:55222 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:56228 Connection attempt to UDP 193.2.4.2:53 from 19387.1587242:53424 Connection attempt to UDP 193.2.4.2:53 from 19387.1587242:61230 Connection attempt to UDP 193.2.4.2:53 from 212823154.242:59716 Connection attempt to UDP 193.2.4.2:53 from 212823154.242:53424 Connection attempt to UDP 193.2.4.2:53 from 19387.154.242:36439 Connection attempt to UDP 193.2.4.2:53 from 19387.154.242:60638 Connection attempt to UDP 193.2.4.2:53 from 19387.1521242:59008 Connection attempt to UDP 193.2.4.2:53 from 19387.1521242:35505 Connection attempt to UDP 193.2.4.2:53 from 19.824154.242:54322 Connection attempt to UDP 193.2.4.2:53 from 19.824154.242:30943 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:51752 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:35165 Connection attempt to UDP 193.2.4.2:53 from 95.87.1587242:36439 Connection attempt to UDP 193.2.4.2:53 from 95.87.1587242:57311 Connection attempt to UDP 193.2.4.2:53 from 19387.1587242:36439 Connection attempt to UDP 193.2.4.2:53 from 19387.1587242:59280 Connection attempt to UDP 193.2.4.2:53 from 19487.154.242:53424 Connection attempt to UDP 193.2.4.2:53 from 19487.154.242:53247 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:35165 Connection attempt to UDP 193.2.4.2:53 from 95.823154.242:50473 Connection attempt to UDP 193.2.4.2:53 from 21287.154.242:56838 Connection attempt to UDP 193.2.4.2:53 from 21287.154.242:63658 Connection attempt to UDP 193.2.4.2:53 from 21287.154.242:54322 Connection attempt to UDP 193.2.4.2:53 from 21287.154.242:60637 ___