kern/44410: policy reference count not decremented correctly on socket close

[Wolfgang.Stukenbrock%nagler-company.com@localhost]

>Number:         44410
>Category:       kern
>Synopsis:       policy reference count not decremented correctly on socket 
>close
>Confidential:   no
>Severity:       serious
>Priority:       high
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Tue Jan 18 14:35:00 +0000 2011
>Originator:     Dr. W. Stukenbrock
>Release:        NetBSD 5.1
>Organization:
Dr. Nagler & Company GmbH
>Environment:
        
        
System: NetBSD test-s0 4.0 NetBSD 4.0 (NSW-WS) #0: Tue Aug 17 17:28:09 CEST 
2010 wgstuken@test-s0:/usr/src/sys/arch/amd64/compile/NSW-WS amd64
Architecture: x86_64
Machine: amd64
>Description:
        If the kernel is compiled with FAST_IPSEC some policy information is 
stored in the PCB of the socket.
        FAST_IPSEC seems to have an additional cache to speed up things.

        Here some things I've figgured out with debugging IPSEC with "sysctl -w 
net-key.debug=0x41":
        remark: the output is after running the system a short time, we start 
with 410 references already lost ...
                I used a small program that sends two UPD-packets to the echo 
port on an other machine with sleep(1)
                between each part.

        I've added some comments about the system calls to the output ...

-- socket(PF_INET, SOCK_DGRAM, 0) ... ipsec_init_policy()

DP key_newsp from ../../../../netipsec/ipsec.c:1176 return SP:0xffff800010207600
DP key_newsp from ../../../../netipsec/ipsec.c:1183 return SP:0xffff80001018ec00

-- sendto echo port of other host

  ... ipsec_getpolicybysock() called from ipsec4_checkpolicy() from ip_output() 
from udp_output()
DP key_allocsp from ../../../../netipsec/ipsec.c:589
DP key_allocsp return SP:0x0 (ID=0) refcnt 0
DP key_allocsp_default from ../../../../netipsec/ipsec.c:591
DP key_allocsp_default returns SP:0xffffffff806948a0 (411)
DP ipsec_getpolicybysock (priv 1 policy 3) allocates SP:0xffffffff806948a0 
(refcnt 411)
DP ipsec_fillpcbcache (dir 2) cause refcnt++:412 SP:0xffffffff806948a0
  ... inside of ipsec4_checkpolicy() - returns NULL
DP key_freesp SP:0xffffffff806948a0 (ID=0) from 
../../../../netipsec/ipsec.c:718; refcnt now 411
  ... ipsec_invalpcbcache(IPSEC_DIR_ANY) called from ipsec_pcbdisconn() from
  ...    in_pcbdisconnect() called after udp_output()
DP key_freesp SP:0xffffffff806948a0 (ID=0) from 
../../../../netipsec/ipsec.c:389; refcnt now 410

-- reply packet

  ... udp4_realinput() called from udp_input() from ip_input()
  ... in_pcblookup_bind() will return a pointer for this packet ...
  ... udp4_sendup called ...
  ... ipsec4_in_reject_so() called - macro for FAST_IPSEC to ipsec4_in_reject() 
...
  ... remark: we have a "inp" pointer -> call ipsec_getpolicybysock() ...
  ... ipsec_checkpcbcache() from ipsec_getpolicybysock() - but nothing in the 
cache
  ... so ipsec4_setspidx_inpcb() is called that calls ipsec_setspidx()
  ... now we try to get the policy - first try specific (failes) then get 
default
DP key_allocsp from ../../../../netipsec/ipsec.c:589
DP key_allocsp return SP:0x0 (ID=0) refcnt 0
DP key_allocsp_default from ../../../../netipsec/ipsec.c:591
DP key_allocsp_default returns SP:0xffffffff806948a0 (411)
  ... debug message of ipsec_getpolicybysock() followed by IN-dir cache setup 
....
DP ipsec_getpolicybysock (priv 1 policy 3) allocates SP:0xffffffff806948a0 
(refcnt 411)
DP ipsec_fillpcbcache (dir 1) cause refcnt++:412 SP:0xffffffff806948a0
  ... back in ipsec4_in_reject() ...
  ... call ipsec_in_reject() that will return OK
  ... free the reference to the policy ...
DP key_freesp SP:0xffffffff806948a0 (ID=0) from 
../../../../netipsec/ipsec.c:1732; refcnt now 411

  ... remark: now a reference to the IN-dir SP is still in the cache !!!!!!!

-- sendto echo port of other host

DP key_allocsp from ../../../../netipsec/ipsec.c:589
DP key_allocsp return SP:0x0 (ID=0) refcnt 0
DP key_allocsp_default from ../../../../netipsec/ipsec.c:591
DP key_allocsp_default returns SP:0xffffffff806948a0 (412)
DP ipsec_getpolicybysock (priv 1 policy 3) allocates SP:0xffffffff806948a0 
(refcnt 412)
DP ipsec_fillpcbcache (dir 2) cause refcnt++:413 SP:0xffffffff806948a0
DP key_freesp SP:0xffffffff806948a0 (ID=0) from 
../../../../netipsec/ipsec.c:718; refcnt now 412
  ... ipsec_invalpcbcache(IPSEC_DIR_ANY) called from ipsec_pcbdisconn() from
  ...    in_pcbdisconnect() called after udp_output()
DP key_freesp SP:0xffffffff806948a0 (ID=0) from 
../../../../netipsec/ipsec.c:389; refcnt now 411
DP key_freesp SP:0xffffffff806948a0 (ID=0) from 
../../../../netipsec/ipsec.c:389; refcnt now 410
  ... remark: this has freed the IN-bound cache entry too (why? not realy 
usefull for the next packet ...)

-- reply packet

  ... udp4_realinput() called from udp_input() from ip_input()
  ... in_pcblookup_bind() will return a pointer for this packet ...
  ... udp4_sendup called ...
  ... ipsec4_in_reject_so() called - macro for FAST_IPSEC to ipsec4_in_reject() 
...
  ... remark: we have a "inp" pointer -> call ipsec_getpolicybysock() ...
  ... ipsec_checkpcbcache() from ipsec_getpolicybysock() - but nothing in the 
cache
  ... so ipsec4_setspidx_inpcb() is called that calls ipsec_setspidx()
  ... now we try to get the policy - first try specific (failes) then get 
default
DP key_allocsp from ../../../../netipsec/ipsec.c:589
DP key_allocsp from ../../../../netipsec/ipsec.c:589
DP key_allocsp return SP:0x0 (ID=0) refcnt 0
DP key_allocsp_default from ../../../../netipsec/ipsec.c:591
DP key_allocsp_default returns SP:0xffffffff806948a0 (411)
  ... debug message of ipsec_getpolicybysock() followed by IN-dir cache setup 
....
DP ipsec_getpolicybysock (priv 1 policy 3) allocates SP:0xffffffff806948a0 
(refcnt 411)
DP ipsec_fillpcbcache (dir 1) cause refcnt++:412 SP:0xffffffff806948a0
  ... back in ipsec4_in_reject() ...
  ... call ipsec_in_reject() that will return OK
  ... free the reference to the policy ...
DP key_freesp SP:0xffffffff806948a0 (ID=0) from 
../../../../netipsec/ipsec.c:1732; refcnt now 411

  ... remark: now a reference to the IN-dir SP is still in the cache !!!!!!!

-- close(socket) ... ipsec4_delete_pcbpolicy()

DP key_freesp SP:0xffff800010207600 (ID=0) from 
../../../../netipsec/ipsec.c:1429; refcnt now 0
DP key_freesp SP:0xffff80001018ec00 (ID=0) from 
../../../../netipsec/ipsec.c:1432; refcnt now 0

  ... XXXXXX reference stored in cache not freed again XXXXXXX

-- exiting 


        Now what has happend ...
        The first packet is send and the answer has been recieved.
        After a recieve operation there is a reference in the cache to the SP 
...
        The second packet will kill the hole cache after sending - including the
        recieve side - not good for performace - the cache will only hit, if 
there is more than
        packet inbound before another packet is send. Hmmm - but that is not 
the point here ...

        After all trafic is done, there is again a reference in the cache, but 
that is
        not freed on socket shutdown ...
        I'm not shure (simply not tested) if this also happens for connection 
oriented protocols.

        During shutdown ipsec4_delete_pcbpolicy() calls ipsec_delpcbpolicy().
        That one simply frees the memory.
        The following patch adds code to this routine to clear the cache prior 
freeing the memeory.
        It seems to solve the problem.

>How-To-Repeat:
        Just enable debugging with "sysctl -w net.key.debu=0x41" on a system 
build with FAST_IPSEC
        and have a look at the reference counter for the policy. No IPSEC rule 
needs to be entered.
>Fix:
        The following fix seems to solve the problem. It clears the cache prior 
freeing the memory
        of the ancor structure in /usr/src/sys/netipsec/ipsec.c

--- ipsec.c.old 2011-01-18 15:31:16.000000000 +0100
+++ ipsec.c     2011-01-18 15:22:36.000000000 +0100
@@ -1160,6 +1160,9 @@
 static void
 ipsec_delpcbpolicy(struct inpcbpolicy *p)
 {
+#ifdef __NetBSD__
+       ipsec_invalpcbcache(p, IPSEC_DIR_ANY);
+#endif
        free(p, M_SECA);
 }
 

>Unformatted: