netfilter buglog - Feb 2017 - [Bug 1119] New: Hash code evicting other entries upon entry deletion (v6.25.1-v6.30)

https://bugzilla.netfilter.org/show_bug.cgi?id=1119

            Bug ID: 1119
           Summary: Hash code evicting other entries upon entry deletion
                    (v6.25.1-v6.30)
           Product: ipset
           Version: unspecified
          Hardware: x86_64
                OS: other
            Status: NEW
          Severity: normal
          Priority: P5
         Component: default
          Assignee: netfilter-buglog at lists.netfilter.org
          Reporter: eje.netfilter at ewanco.com

Created attachment 492
  --> https://bugzilla.netfilter.org/attachment.cgi?id=492&action=edit
Bash script to demonstrate eviction of entries

ipset (v6.30, v6.29, v6.25.1, but not v6.21.1) hash code is sometimes evicting
(or bumping) as a side-effect other entries in the set upon entry deletion
(ipset del).  The symptom of this is that you get the error "ipset v6.30:
Element cannot be deleted from the set: it's not added" when deleting
an entry
that has not yet been legitimately deleted. The problem happens with a large
number of entries; in some cases I've seen it with under 700 entries but
typically it takes over 1,000 entries.  I've seen one, two, even three or
four
entries evicted on a deletion.

To reproduce the problem, do one of two things.  You can use the data in the
ipset tests directory (tests/iphash.t.large), or you can generate a fresh
sequence.  In the first case, do:

  ipset restore < tests/iphash.t.large

In the second case, do:

  ipset create test hash:ip
  len=1024; for ((x=0; x <= len; ++x)); do ipset add test 1.$((x >>
8)).$((x &
255)).1; done

Then, to reproduce the problem, simply delete all the entries, one-by-one:

  ipset list test | sed '1,/Members/d' | xargs -n1 ipset del test

You'll get:

ipset v6.30: Element cannot be deleted from the set: it's not added
ipset v6.30: Element cannot be deleted from the set: it's not added
ipset v6.30: Element cannot be deleted from the set: it's not added
ipset v6.30: Element cannot be deleted from the set: it's not added
ipset v6.30: Element cannot be deleted from the set: it's not added
ipset v6.30: Element cannot be deleted from the set: it's not added

This error is issued when you try to delete the evicted entries.

If you cannot reproduce the problem initially, increase the data set or delete
and recreate the set to choose a new random hash seed.

I know entries are being evicted because I wrote a script to list the set after
each deletion and keep track of entries that had disappeared. 

The behavior is consistent for any given random hash seed; in other words, you
can repeat the test and get the exact same results so long as you do not delete
the set.  If you delete and recreate the set, you get different addresses
evicted, but it still fails.  It fails consistently across different hash types
and is consistently reproducible (depending on hash seed and set size).
Flushing the set does not issue an error.

This is the listing of a set that's failed after all its entries have been
removed.  Note the size of memory and number of entries compared to the flushed
version:

~/ipset/src # ipset list test
Name: test
Type: hash:ip
Revision: 4
Header: family inet hashsize 1024 maxelem 65536
Size in memory: 13128
References: 0
Number of entries: 3
Members:
~/ipset/src # ipset flush test
~/ipset/src # ipset list test 
Name: test
Type: hash:ip
Revision: 4
Header: family inet hashsize 1024 maxelem 65536
Size in memory: 120
References: 0
Number of entries: 0
Members:
~/ipset/src #

I've attached a script that demonstrates that the error is caused by entries
that are getting evicted as a side-effect: ipset-track-hash.  It takes a file
with a list of entries, adds them to the set "test" if they aren't
already in
there, and then deletes all of them one-by-one, counting how many are lost
after each deletion and determining which entries were lost:

:~ # ipset x test -q
:~ # ipset restore < tests/iphash.t.large
:~ # ipset list test | sed '1,/Members/d' > /tmp/ipset-tens
:~ # ./ipset-track-hash /tmp/ipset-tens 
Deleting ...
721:LS 335/334 10.10.3.240
753:LS 302/301 10.10.2.149
835:LS 219/218 10.10.0.104
932:Expected count (122) but failed
975:Expected count (80) but failed
996:Expected count (60) but failed
Failed: 3

The prefixed number with a colon is the input line number.  "LS" means
"Lost an
entry but Successful deletion", followed by the expected entries/actual
entries
and the evicted entry(ies). 

The problem does not occur in v6.21.1:

:~ # ipset create test2 hash:ip 
ipset v6.21.1: Set cannot be created: set with the same name already exists
:~ # ipset x test2
:~ # ipset create test2 hash:ip
:~ # while read ip; do ipset add test2 $ip; done < /tmp/ipset-10k
:~ # while read ip; do ipset del test2 $ip; done < /tmp/ipset-10k
:~ # 

I tried to build 6.23 and 6.22 but could not due to an error resulting from
some sort of a weird pre-processor interaction.  (Somehow "struct
ip_set_counter_match" is being preprocessed into "struct
ip_set_counter_match0"
in ../include/uapi/linux/netfilter/xt_set.h:70:31 causing an "error: field
'bytes' has incomplete type".)

The platform is GNU/Linux, openSUSE 42.2 (v6.29 stock and v6.30 built from
git), openSUSE 42.1 (v6.25.1), and openSUSE 13.1 (v6.21.1).

While I'm convinced this is a kernel bug, I am filing it under ipset
userspace,
because I can't determine where ipset kernel code bugs should be reported;
so I
apologize if this is misfiled.

-- 
You are receiving this mail because:
You are watching all bug changes.
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.netfilter.org/pipermail/netfilter-buglog/attachments/20170208/213b0306/attachment.html>

https://bugzilla.netfilter.org/show_bug.cgi?id=1119

Jozsef Kadlecsik <kadlec at netfilter.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |kadlec at netfilter.org

--- Comment #1 from Jozsef Kadlecsik <kadlec at netfilter.org> ---
Created attachment 494
  --> https://bugzilla.netfilter.org/attachment.cgi?id=494&action=edit
hash-del-bug.patch

-- 
You are receiving this mail because:
You are watching all bug changes.
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.netfilter.org/pipermail/netfilter-buglog/attachments/20170211/a862d647/attachment.html>

https://bugzilla.netfilter.org/show_bug.cgi?id=1119

--- Comment #2 from Jozsef Kadlecsik <kadlec at netfilter.org> ---
Thanks for the very thorough bug report, I could reproduce it easily.
Please try the attached patch, according to my tests it fixes the bug.

-- 
You are receiving this mail because:
You are watching all bug changes.
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.netfilter.org/pipermail/netfilter-buglog/attachments/20170211/117c2561/attachment.html>

https://bugzilla.netfilter.org/show_bug.cgi?id=1119

Eric Ewanco <eje.netfilter at ewanco.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
         Resolution|---                         |FIXED
             Status|NEW                         |RESOLVED

--- Comment #3 from Eric Ewanco <eje.netfilter at ewanco.com> ---
Thank you for the quick response.  The problem is resolved.

-- 
You are receiving this mail because:
You are watching all bug changes.
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.netfilter.org/pipermail/netfilter-buglog/attachments/20170215/702af27d/attachment.html>