Thread (63 messages) 63 messages, 4 authors, 2010-02-04

Re: debug: nt_conntrack and KVM crash

From: Jon Masters <hidden>
Date: 2010-01-30 01:57:26
Also in: lkml, netfilter-devel

On Fri, 2010-01-29 at 20:10 -0500, Jon Masters wrote:
quoted hunk ↗ jump to hunk
Folks,

I've hooked up Jason's kgb/kgdb patches and been able to gather some
more information about the most recent crashes on this test system.

The last few crashes have occurred after starting an F12 guest, at which
point __nf_conntrack_find is called with the following tuple:
--- begin ---
(gdb) print tuple->src->u3
$45 = {all = {16777343, 0, 0, 0}, ip = 16777343, ip6 = {16777343, 0, 0,
0},
  in = {s_addr = 16777343}, in6 = {in6_u = {
      u6_addr8 = "\177\000\000\001", '\000' <repeats 11 times>,
u6_addr16 = {
        127, 256, 0, 0, 0, 0, 0, 0}, u6_addr32 = {16777343, 0, 0, 0}}}}

(gdb) print tuple->src->u
$46 = {all = 3607, tcp = {port = 3607}, udp = {port = 3607}, icmp = {
    id = 3607}, dccp = {port = 3607}, sctp = {port = 3607}, gre = {key =
3607}}

(gdb) print tuple->dst
$48 = {u3 = {all = {16777343, 0, 0, 0}, ip = 16777343, ip6 = {16777343,
0, 0,
      0}, in = {s_addr = 16777343}, in6 = {in6_u = {
        u6_addr8 = "\177\000\000\001", '\000' <repeats 11 times>,
u6_addr16 = {
          127, 256, 0, 0, 0, 0, 0, 0}, u6_addr32 = {16777343, 0, 0,
0}}}},
  u = {all = 12761, tcp = {port = 12761}, udp = {port = 12761}, icmp = {
      type = 217 '\331', code = 49 '1'}, dccp = {port = 12761}, sctp = {
      port = 12761}, gre = {key = 12761}}, protonum = 6 '\006', dir = 0
'\000'}
---end ---

Which (after converting from network to host addressing) is a VNC (port
5902) TCP packet being broadcast (by the guest maybe? I didn't know
Fedora started VNC by default these days, but I'll look).

After looking through the netfilter code, I understand now that it
maintains a hashtable (which size is computed at boot time according to
system memory size, and is usually kmalloced but might be vmalloced if
there is a problem - not here though). Each time a packet of interest
relating to a connection we might want to track comes in, we get a
"tuple" passed in to the conntrack functions, and this is hashed using
hash_conntrack into an entry in an array of hlists (buckets) stored in
the "ct" (conntrack) entry in the current network namespace (there is
only one on this system, I checked that). In this case, when we come to
look at the hashtable, it contains a number of valid entries (I looked)
but not for the hashed entry calculated for this VNC packet.

I would love to have advice on the best way to debug conntrack hashtable
missbehavior (there's a lot of RCU use in there), especially with
freeing entries. Is there more debug code I can turn on? Is there
anything you guys would suggest that I look at?
Ah so I should have realized before but I wasn't looking at valid values
for the range of the hashtable yet, nf_conntrack_htable_size is getting
wildly out of whack. It goes from:

(gdb) print nf_conntrack_hash_rnd
$1 = 2688505299
(gdb) print nf_conntrack_htable_size
$2 = 16384

nf_conntrack_events: 1
nf_conntrack_max: 65536

Shortly after booting, before being NULLed shortly after starting some
virtual machines (the hash isn't reset, whereas it is recomputed if the
hashtable is re-initialized after an intentional resizing operation):

(gdb) print nf_conntrack_hash_rnd
$3 = 2688505299
(gdb) print nf_conntrack_htable_size
$4 = 0

nf_conntrack_events: 1
nf_conntrack_max: 0
nf_conntrack_buckets: 0

Then when I start the third virtual machine:

(gdb) print nf_conntrack_hash_rnd
$15 = 2688505299
(gdb) print nf_conntrack_htable_size
$16 = 2180904176

And we're done. Which is great. But I don't think it's random corruption
since it's reproducible by a number of people on different hardware. So
hopefully for some reason this is being deliberately screwified.

Jon.
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help