Re: net.inet.udp.log_in_vain strange syslog reports

2017-02-15 Thread Eric van Gyzen

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-15 Thread Mark Martinec

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

2017-02-06 Thread Eric van Gyzen
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

2017-02-06 Thread Mark Martinec

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

2017-02-03 Thread Eric van Gyzen

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

2017-02-02 Thread Mark Martinec

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