Bug 137317

Summary: [tcp] logs full of syncache problems
Product: Base System Reporter: kause lotski <kauselot>
Component: kernAssignee: Andre Oppermann <andre>
Status: Closed FIXED    
Severity: Affects Only Me    
Priority: Normal    
Version: Unspecified   
Hardware: Any   
OS: Any   
Attachments:
Description Flags
patch-1.diff none

Description kause lotski 2009-07-31 23:20:03 UTC
My logs are beeind flooded with messages like this:

Jul 31 23:58:00 premetenec kernel: TCP: [213.253.92.100]:11711 to [xxxxxxxx]:80 tcpflags 0x11<FIN,ACK>; syncache_expand: Segment failed SYNCOOKIE authentication, segment rejected (probably spoofed)
Aug  1 00:00:37 premetenec kernel: TCP: [213.253.92.100]:30837 to [xxxxxxxx]:80 tcpflags 0x11<FIN,ACK>; syncache_expand: Segment failed SYNCOOKIE authentication, segment rejected (probably spoofed)
Aug  1 00:00:41 premetenec kernel: TCP: [83.218.196.142]:1579 to [xxxxxxxx]:25 tcpflags 0x4<RST>; syncache_chkrst: Spurious RST without matching syncache entry (possibly syncookie only), segment ignored
Aug  1 00:00:52 premetenec kernel: TCP: [193.198.80.29]:2524 to [xxxxxxxx]:80 tcpflags 0x2<SYN>; _syncache_add: Received duplicate SYN, resetting timer and retransmitting SYN|ACK
Aug  1 00:01:01 premetenec kernel: TCP: [190.109.157.30]:15396 to [91.185.206.35]:25 tcpflags 0x10<ACK>; syncache_expand: Segment failed SYNCOOKIE authentication, segment rejected (probably spoofed)
Aug  1 00:01:01 premetenec kernel: TCP: [xxxxxxxx]:3353 to [xxxxxxxx]:995 tcpflags 0x4<RST>; syncache_chkrst: Spurious RST without matching syncache entry (possibly syncookie only), segment ignored
Aug  1 00:01:05 premetenec kernel: TCP: [213.253.92.100]:12391 to [xxxxxxxx]:80 tcpflags 0x11<FIN,ACK>; syncache_expand: Segment failed SYNCOOKIE authentication, segment rejected (probably spoofed)
Aug  1 00:02:55 premetenec kernel: TCP: [213.253.92.100]:9833 to [xxxxxxxx]:80 tcpflags 0x11<FIN,ACK>; syncache_expand: Segment failed SYNCOOKIE authentication, segment rejected (probably spoofed)
Aug  1 00:03:54 premetenec kernel: TCP: [213.253.92.100]:6298 to [xxxxxxxx]:80 tcpflags 0x11<FIN,ACK>; syncache_expand: Segment failed SYNCOOKIE authentication, segment rejected (probably spoofed)

Among ip's that are creating this are: my ip, servers own ip, and google! Nearly all messages are apache or pop3-ssl related.

sysctl net.inet.tcp.log_debug=0 does nothing.
Comment 1 Mark Linimon freebsd_committer freebsd_triage 2009-08-01 00:51:52 UTC
Responsible Changed
From-To: freebsd-bugs->freebsd-net

Over to maintainer(s).
Comment 2 kause lotski 2009-10-13 08:43:36 UTC
perhaps some more information would help:
I'm experiencing this on two different boxes with totally different hardware, one located at datacenter and connected via LAN and second one that is sitting on ADSL line. 
I have tried all sysctl variables that I could find remotely related to this with no luck, tried compiling kernel with and without DUMMYNET

This are  kernel customizations I use:
options         IPFIREWALL
options         IPFIREWALL_VERBOSE
options         IPFIREWALL_VERBOSE_LIMIT=100
options         DUMMYNET
options         HZ=1000    # strongly recommended
options         IPDIVERT
options         IPSTEALTH               #support for stealth forwarding

options         ACCEPT_FILTER_HTTP      # Must be here or AcceptFilter won't work w/Apache2
options         DEVICE_POLLING          # Imporoves network driver performance
options         ZERO_COPY_SOCKETS
device          coretemp                # On-die temperature sensor on Intel Core and newer CPUs


Is it at least possible to turn of this checks for local IP's - it is most disturbing that I'm getting droped packets at apache jail to mysql jail communication?
Comment 3 Andre Oppermann freebsd_committer freebsd_triage 2010-08-10 23:20:02 UTC
Responsible Changed
From-To: freebsd-net->andre

Take over.
Comment 4 Andre Oppermann freebsd_committer freebsd_triage 2010-08-16 22:36:20 UTC
Kause,

the likely cause for your TCP log messages is another sysctl with
the name of "net.inet.tcp.log_in_vain" which you have enabled.
It has the side effect of also silently causing the other debug
output to be generated as with "net.inet.tcp.log_debug".

Please check the setting of "net.inet.tcp.log_in_vain" and disable
it to stop the log messages.

Please report back whether this fixed your problem or not.

-- 
Andre
Comment 5 Andre Oppermann freebsd_committer freebsd_triage 2010-08-16 22:38:29 UTC
State Changed
From-To: open->feedback
Comment 6 kause lotski 2010-08-17 02:45:35 UTC
Tried net.inet.tcp.log_in_vain=0 and it indeed helps, but - 
it also kills listening to incoming connections to closed ports, which I need to 
have logged. It  worked ok (or at least seemed to) in 6.x - any way to get this 
in 7/8 ?


Regards
Kause


________________________________
From: Andre Oppermann <andre@freebsd.org>
To: kauselot@yahoo.com
Cc: bug-followup@freebsd.org
Sent: Mon, August 16, 2010 11:36:20 PM
Subject: Re: kern/137317: [tcp] logs full of syncache problems

Kause,

the likely cause for your TCP log messages is another sysctl with
the name of "net.inet.tcp.log_in_vain" which you have enabled.
It has the side effect of also silently causing the other debug
output to be generated as with "net.inet.tcp.log_debug".

Please check the setting of "net.inet.tcp.log_in_vain" and disable
it to stop the log messages.

Please report back whether this fixed your problem or not.

-- Andre


      
Comment 7 Andre Oppermann freebsd_committer freebsd_triage 2010-08-17 10:20:42 UTC
On 17.08.2010 03:45, kause lotski wrote:
> Tried net.inet.tcp.log_in_vain=0 and it indeed helps, but -
> it also kills listening to incoming connections to closed ports, which I need to
> have logged. It  worked ok (or at least seemed to) in 6.x - any way to get this
> in 7/8 ?

It's the same in FreeBSD 7 and 8.  I've changed the code to properly
differentiate between log_in_vain and log_debug.  Would be great if
you could test it.  It's against current but should also apply to 8
and 7, possibly 6.

-- 
Andre
Comment 8 Andre Oppermann freebsd_committer freebsd_triage 2010-08-17 10:21:36 UTC
State Changed
From-To: feedback->analyzed
Comment 9 dfilter service freebsd_committer freebsd_triage 2010-08-18 18:40:09 UTC
Author: andre
Date: Wed Aug 18 17:39:47 2010
New Revision: 211462
URL: http://svn.freebsd.org/changeset/base/211462

Log:
  Untangle the net.inet.tcp.log_in_vain and net.inet.tcp.log_debug
  sysctl's and remove any side effects.
  
  Both sysctl's share the same backend infrastructure and due to the
  way it was implemented enabling net.inet.tcp.log_in_vain would also
  cause log_debug output to be generated.  This was surprising and
  eventually annoying to the user.
  
  The log output backend is kept the same but a little shim is inserted
  to properly separate log_in_vain and log_debug and to remove any side
  effects.
  
  PR:		kern/137317
  MFC after:	1 week

Modified:
  head/sys/netinet/tcp_input.c
  head/sys/netinet/tcp_subr.c
  head/sys/netinet/tcp_var.h

Modified: head/sys/netinet/tcp_input.c
==============================================================================
--- head/sys/netinet/tcp_input.c	Wed Aug 18 15:58:26 2010	(r211461)
+++ head/sys/netinet/tcp_input.c	Wed Aug 18 17:39:47 2010	(r211462)
@@ -571,7 +571,7 @@ findpcb:
 		 */
 		if ((tcp_log_in_vain == 1 && (thflags & TH_SYN)) ||
 		    tcp_log_in_vain == 2) {
-			if ((s = tcp_log_addrs(NULL, th, (void *)ip, ip6)))
+			if ((s = tcp_log_vain(NULL, th, (void *)ip, ip6)))
 				log(LOG_INFO, "%s; %s: Connection attempt "
 				    "to closed port\n", s, __func__);
 		}

Modified: head/sys/netinet/tcp_subr.c
==============================================================================
--- head/sys/netinet/tcp_subr.c	Wed Aug 18 15:58:26 2010	(r211461)
+++ head/sys/netinet/tcp_subr.c	Wed Aug 18 17:39:47 2010	(r211462)
@@ -268,6 +268,8 @@ VNET_DEFINE(uma_zone_t, sack_hole_zone);
 
 static struct inpcb *tcp_notify(struct inpcb *, int);
 static void	tcp_isn_tick(void *);
+static char *	tcp_log_addr(struct in_conninfo *inc, struct tcphdr *th,
+		    void *ip4hdr, const void *ip6hdr);
 
 /*
  * Target size of TCP PCB hash tables. Must be a power of two.
@@ -2234,9 +2236,33 @@ SYSCTL_PROC(_net_inet_tcp, TCPCTL_DROP, 
  * and ip6_hdr pointers have to be passed as void pointers.
  */
 char *
+tcp_log_vain(struct in_conninfo *inc, struct tcphdr *th, void *ip4hdr,
+    const void *ip6hdr)
+{
+
+	/* Is logging enabled? */
+	if (tcp_log_in_vain == 0)
+		return (NULL);
+
+	return (tcp_log_addr(inc, th, ip4hdr, ip6hdr));
+}
+
+char *
 tcp_log_addrs(struct in_conninfo *inc, struct tcphdr *th, void *ip4hdr,
     const void *ip6hdr)
 {
+
+	/* Is logging enabled? */
+	if (tcp_log_debug == 0)
+		return (NULL);
+
+	return (tcp_log_addr(inc, th, ip4hdr, ip6hdr));
+}
+
+static char *
+tcp_log_addr(struct in_conninfo *inc, struct tcphdr *th, void *ip4hdr,
+    const void *ip6hdr)
+{
 	char *s, *sp;
 	size_t size;
 	struct ip *ip;
@@ -2259,10 +2285,6 @@ tcp_log_addrs(struct in_conninfo *inc, s
 	    2 * INET_ADDRSTRLEN;
 #endif /* INET6 */
 
-	/* Is logging enabled? */
-	if (tcp_log_debug == 0 && tcp_log_in_vain == 0)
-		return (NULL);
-
 	s = malloc(size, M_TCPLOG, M_ZERO|M_NOWAIT);
 	if (s == NULL)
 		return (NULL);

Modified: head/sys/netinet/tcp_var.h
==============================================================================
--- head/sys/netinet/tcp_var.h	Wed Aug 18 15:58:26 2010	(r211461)
+++ head/sys/netinet/tcp_var.h	Wed Aug 18 17:39:47 2010	(r211462)
@@ -611,6 +611,8 @@ void	 tcp_destroy(void);
 void	 tcp_fini(void *);
 char 	*tcp_log_addrs(struct in_conninfo *, struct tcphdr *, void *,
 	    const void *);
+char	*tcp_log_vain(struct in_conninfo *, struct tcphdr *, void *,
+	    const void *);
 int	 tcp_reass(struct tcpcb *, struct tcphdr *, int *, struct mbuf *);
 void	 tcp_reass_init(void);
 #ifdef VIMAGE
_______________________________________________
svn-src-all@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/svn-src-all
To unsubscribe, send any mail to "svn-src-all-unsubscribe@freebsd.org"
Comment 10 Andre Oppermann freebsd_committer freebsd_triage 2010-08-18 20:25:55 UTC
State Changed
From-To: analyzed->patched
Comment 11 Andre Oppermann freebsd_committer freebsd_triage 2010-08-19 19:57:44 UTC
Thanks for the feedback.  The patches are the same.  The first one is the
one I sent you directly and the second one is what I already committed to
SVN in head.  They are identical, hence the warning you got.  In a few days
I will also apply the patch to 8 and 7.  You should revert the manually
applied patch then.

-- 
Andre

On 19.08.2010 20:25, kause lotski wrote:
> Applied v-1 patch to RELENG-8 and it seems to work as intended  for now.
>
> Is v2 any different ot is it just made for another brancg/version? Had some
> problems triing to apply it (reverse or already applied patch detected for the
> first file)
>
> Kause
>
>
>
>
> ________________________________
> From: "andre@FreeBSD.org"<andre@FreeBSD.org>
> To: kauselot@yahoo.com; andre@FreeBSD.org; andre@FreeBSD.org
> Sent: Wed, August 18, 2010 9:26:19 PM
> Subject: Re: kern/137317: [tcp] logs full of syncache problems
>
> Synopsis: [tcp] logs full of syncache problems
>
> State-Changed-From-To: analyzed->patched
> State-Changed-By: andre
> State-Changed-When: Wed Aug 18 19:25:55 UTC 2010
> State-Changed-Why:
>
> http://www.freebsd.org/cgi/query-pr.cgi?pr=137317
Comment 12 Andre Oppermann freebsd_committer freebsd_triage 2010-08-23 15:23:48 UTC
State Changed
From-To: patched->closed

All MFC's done.