Project

General

Profile

Actions

Bug #968

closed

panic: assertion: _ifac->ifa_magic == IFA_CONTAINER_MAGIC in _IFAFREE

Added by qhwt+dfly about 16 years ago. Updated almost 16 years ago.

Status:
Closed
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
Start date:
Due date:
% Done:

0%

Estimated time:

Description

Hello.
Just caught a panic while playing with NFS mounted git tree
(but I cannot reliably reproduce it after that):

panic: assertion: _ifac->ifa_magic == IFA_CONTAINER_MAGIC in _IFAFREE
mp_lock = 00000001; cpuid = 1
:

and the backtrace below the panic is as follows:

#9 0xc032907e in rtfree (rt=0xc116ca60)
at /home/dfly/current/sys/net/if_var.h:469
#10 0xc034e8ed in ip_output (m0=0xcc2fd100, opt=0x0, ro=0xc9ebde3c,
flags=<value optimized out>, imo=0x0, inp=0xc9ebde00)
at /home/dfly/current/sys/netinet/ip_output.c:245
#11 0xc035c527 in udp_send (so=0xc9de17a0, flags=0, m=0xcc2fed00, addr=0x0,
control=0x0, td=0xc8afc500)
at /home/dfly/current/sys/netinet/udp_usrreq.c:781
#12 0xc02ea5ff in netmsg_pru_send (msg=0xcc33da70)
at /home/dfly/current/sys/kern/uipc_msg.c:527
#13 0xc03274e6 in netmsg_service_loop (arg=0x0)
at /home/dfly/current/sys/net/netisr.c:242
#14 0xc02c1ad5 in lwkt_deschedule_self (td=Cannot access memory at address 0x8
)
at /home/dfly/current/sys/kern/lwkt_thread.c:214

This is with an SMP kernel (just added SMP and APIC_IO to GENERIC config)
built from source tree as of March 10-11. The kernel is running on VMware
and the host OS is exporting the git tree via NFS. Before seeing the panic,
(but not right before the panic) the system clock on the guest OS skewed
about 20000 seconds by rdate command after resuming the host OS from sleep.
I'm not sure that skewing the system clock has anything to do with the panic,
though.

The kernel image and the vmcore file are in my leaf account, ~y0netan1/crash

Cheers.

Actions #1

Updated by sepherosa about 16 years ago

dst address of a UDP packet is changed, which changes port/addr hash
too, but old route entry was not allocated on the current CPU. Since
the box only contains 2 CPUs, after the l{port,addr}/f{port,addr}
hash, the problem probably will not show itself ;). Please run
following test program several times and then unload the NIC module to
see whether you could reproduce the problem (if you have TCP
connections too, you will have to wait 2MSL):
http://leaf.dragonflybsd.org/~sephe/test_udp.c

Also, please test following patch:
http://leaf.dragonflybsd.org/~sephe/rtfree_remote.diff

Best Regards,
sephe

Actions #2

Updated by dillon about 16 years ago

:Hello.
:Just caught a panic while playing with NFS mounted git tree
:(but I cannot reliably reproduce it after that):
:
:panic: assertion: _ifac->ifa_magic == IFA_CONTAINER_MAGIC in _IFAFREE
:mp_lock = 00000001; cpuid = 1
: :
:and the backtrace below the panic is as follows:
:
:#9 0xc032907e in rtfree (rt=0xc116ca60)
: at /home/dfly/current/sys/net/if_var.h:469
:#10 0xc034e8ed in ip_output (m0=0xcc2fd100, opt=0x0, ro=0xc9ebde3c,
: flags=<value optimized out>, imo=0x0, inp=0xc9ebde00)
: at /home/dfly/current/sys/netinet/ip_output.c:245

I assume IFA_CONTAINER_MAGIC is a sanity check you added somewhere
in your local tree? Its a good idea but probably catches the
bug too late.
We definitely still have a use-after-free issue with IFA's.  I have
been unable to locate where but clearly something is losing track of
the IFA and we are winding up with a dangling pointer.
-Matt
Actions #3

Updated by sepherosa about 16 years ago

On Mon, Mar 17, 2008 at 3:53 AM, Matthew Dillon
<> wrote:

:Hello.

:Just caught a panic while playing with NFS mounted git tree
:(but I cannot reliably reproduce it after that):
:
:panic: assertion: _ifac->ifa_magic == IFA_CONTAINER_MAGIC in _IFAFREE
:mp_lock = 00000001; cpuid = 1
: :
:and the backtrace below the panic is as follows:
:
:#9 0xc032907e in rtfree (rt=0xc116ca60)
: at /home/dfly/current/sys/net/if_var.h:469
:#10 0xc034e8ed in ip_output (m0=0xcc2fd100, opt=0x0, ro=0xc9ebde3c,
: flags=<value optimized out>, imo=0x0, inp=0xc9ebde00)
: at /home/dfly/current/sys/netinet/ip_output.c:245

I assume IFA_CONTAINER_MAGIC is a sanity check you added somewhere
in your local tree? Its a good idea but probably catches the

Nah, it is in the cvs repos. I added that when parallelize ifnet.if_addrhead.

It could catch problems like freeing/allocating rtentry on different
CPU (e.g. the TCP connection problem, I fixed before release).

The problem YONETANI had seen is caused by allocating/freeing rtentry
on different CPU:
1) connect(2) is not called on UDP socket
2) One UDP datagram was sent to dst1/port1 on the socket, given
port/addr hash dispatches the sending to CPUX. rtentry was allocated
on CPUX and was installed/referenced in this socket's inpcb
3) Sometime later, the rtentry is removed from radix tree, but the UDP
socket is not closed. Given it contains the last reference of the
rtentry
4) Another UDP datagram is sent to dst2/port2 on the socket, port/addr
hash dispatches the sending to CPUY. Since dst1 != dst2 then rtentry
in socket's inpcb would be freed on CPUY. Thus the panic happens

Best Regards,
sephe

Actions #4

Updated by qhwt+dfly about 16 years ago

I've been trying to reproduce it but so far unsuccessful...

Actions #5

Updated by qhwt+dfly about 16 years ago

Oh, I forgot to mention that the last command before the panic was df
(shown as thread ID 1), if that matters.

Cheers.

Actions #6

Updated by sepherosa about 16 years ago

On Mon, Mar 17, 2008 at 11:06 AM, YONETANI Tomokazu
<> wrote:

On Sun, Mar 16, 2008 at 08:09:17PM +0800, Sepherosa Ziehau wrote:

On Sun, Mar 16, 2008 at 6:07 PM, YONETANI Tomokazu <> wrote:

Hello.
Just caught a panic while playing with NFS mounted git tree
(but I cannot reliably reproduce it after that):

dst address of a UDP packet is changed, which changes port/addr hash
too, but old route entry was not allocated on the current CPU. Since
the box only contains 2 CPUs, after the l{port,addr}/f{port,addr}
hash, the problem probably will not show itself ;). Please run
following test program several times and then unload the NIC module to
see whether you could reproduce the problem (if you have TCP
connections too, you will have to wait 2MSL):
http://leaf.dragonflybsd.org/~sephe/test_udp.c

I've been trying to reproduce it but so far unsuccessful...

I have changed this test program a little bit. Run it in following way:
./test_udp remote_ip

If it paused, then on the other term:
ifconfig iface_local down
And kill test_udp, if you don't have TCP connection, the panic should
happen immediately.

Though the panic place is different, but the root cause should be same:
Initially UDP socket is neither connected nor bound, thus f{addr,port}
and l{addr,port} in pcb are 0. Sending the first datagram on this
socket will be dispatched to CPU0. Then lport is chosen in
udp_output() and route entry is allocated on CPU0. If (lport >> 8 &
1) is 1 on a 2 CPU box, then rest of socket operation will happen on
CPU1, e.g. sending to different faddr will cause route entry allocated
on CPU0 be freed on CPU1.

I think we need to fix following entry points:
1) udp_output(): after ip_output() if old_lport==0 and
mycpuid!=udp_addrcpu(inpcb addr/port pair) then free inpcb's route
entry
2) udp_connect(): this function always happens on CPU0, so if
udp_addrcpu(inpcb addr/port pair)!=mycpuid(0 here), then we need to
free inpcb's route entry
3) udp_disconnect(): at the end of it, if mycpuid!=udp_addrcpu(inpcb
addr/port pair) then free inpcb's route entry

I may miss some entry points here, so please point them out to me, if
some pop up in your mind.

Best Regards,
sephe

Actions #7

Updated by dillon about 16 years ago

:I have changed this test program a little bit. Run it in following way:
:./test_udp remote_ip
:
:...
:I think we need to fix following entry points:
:1) udp_output(): after ip_output() if old_lport==0 and
:mycpuid!=udp_addrcpu(inpcb addr/port pair) then free inpcb's route
:entry
:2) udp_connect(): this function always happens on CPU0, so if
:udp_addrcpu(inpcb addr/port pair)!=mycpuid(0 here), then we need to
:free inpcb's route entry
:3) udp_disconnect(): at the end of it, if mycpuid!=udp_addrcpu(inpcb
:addr/port pair) then free inpcb's route entry
:
:I may miss some entry points here, so please point them out to me, if
:some pop up in your mind.
:
:Best Regards,
:sephe

I'm not sure how appropriate my idea is but... what if we simply
do not cache the route until after the addr/port pair is assigned?
-Matt
Matthew Dillon
&lt;&gt;
Actions #8

Updated by dillon about 16 years ago

:I have changed this test program a little bit. Run it in following way:
:./test_udp remote_ip
:
:If it paused, then on the other term:
:ifconfig iface_local down
:And kill test_udp, if you don't have TCP connection, the panic should
:happen immediately.

I'm not sure if I'm using the right patch set.  With your 
rtfree_remote.diff and your latest test regimen I am getting
numerous "remote rtfree 1->0" messages on the console when I test
with a vkernel -n 2, but not getting a crash.
-Matt
Actions #9

Updated by qhwt+dfly about 16 years ago

Yes! But this time at a different place:
#9 0xc0328dc2 in rtrequest1 (req=11, rtinfo=0xca77ec9c, ret_nrt=0xca77ecf0)
at /home/dfly/current/sys/net/if_var.h:445
#10 0xc032915f in rtrequest (req=11, dst=0xca77ed14, gateway=0x0, netmask=0x0,
flags=0, ret_nrt=0xca77ecf0) at /home/dfly/current/sys/net/route.c:637
#11 0xc0329386 in _rtlookup (dst=0xca77ed14, generate_report=1, ignore=0)
at /home/dfly/current/sys/net/route.c:275
#12 0xc0343642 in arplookup (addr=30085292, create=1, proxy=-1067129044)
at /home/dfly/current/sys/net/route.h:364
#13 0xc034371a in arp_update_oncpu (m=<value optimized out>, saddr=30085292,
create=28790, dologging=0) at /home/dfly/current/sys/netinet/if_ether.c:563
#14 0xc0343f66 in arp_update_msghandler (netmsg=0xc985bd08)
at /home/dfly/current/sys/netinet/if_ether.c:877
#15 0xc03284a2 in rtable_service_loop (dummy=0x0)
at /home/dfly/current/sys/net/route.c:178
#16 0xc02c12e5 in lwkt_deschedule_self (td=Cannot access memory at address 0x8
)
at /home/dfly/current/sys/kern/lwkt_thread.c:214

So, can I start testing your patch, or do you need an update to it?

Thanks.

Actions #10

Updated by sepherosa about 16 years ago

On Tue, Mar 18, 2008 at 4:48 AM, Matthew Dillon
<> wrote:

:I have changed this test program a little bit. Run it in following way:
:./test_udp remote_ip
:
:...
:I think we need to fix following entry points:

:1) udp_output(): after ip_output() if old_lport==0 and
:mycpuid!=udp_addrcpu(inpcb addr/port pair) then free inpcb's route
:entry
:2) udp_connect(): this function always happens on CPU0, so if
:udp_addrcpu(inpcb addr/port pair)!=mycpuid(0 here), then we need to
:free inpcb's route entry
:3) udp_disconnect(): at the end of it, if mycpuid!=udp_addrcpu(inpcb
:addr/port pair) then free inpcb's route entry
:
:I may miss some entry points here, so please point them out to me, if
:some pop up in your mind.
:
:Best Regards,
:sephe

I'm not sure how appropriate my idea is but... what if we simply
do not cache the route until after the addr/port pair is assigned?

This is probably same as 1). We still need to fix 2) and 3).

Best Regards,
sephe

Actions #11

Updated by sepherosa about 16 years ago

On Tue, Mar 18, 2008 at 5:53 AM, Matthew Dillon
<> wrote:

:I have changed this test program a little bit. Run it in following way:

:./test_udp remote_ip
:
:If it paused, then on the other term:
:ifconfig iface_local down
:And kill test_udp, if you don't have TCP connection, the panic should
:happen immediately.

I'm not sure if I'm using the right patch set. With your
rtfree_remote.diff and your latest test regimen I am getting
numerous "remote rtfree 1->0" messages on the console when I test
with a vkernel -n 2, but not getting a crash.

This patch is a workaround instead of real fix: it only makes sure
that route entry allocated on CPU0 is freed on CPU0, but it may still
be accessed by CPU1 before being freed. The test program will not
cause panic with this patch in place.

There is one thing I want to get into cvs in this patch:
- Add rt_cpuid in rtentry
It at least could help debugging problems. And we may want to assert
route entry is only accessed by owner CPU using this field.

Best Regards,
sephe

Actions #12

Updated by sepherosa about 16 years ago

This panic is not what I had expected though :) Could you get a coredump?

Nah, it is a workaround. You can use it to prevent the panic upon
rtfree. I will work out a real fix by patching various udp functions
I mentioned when I get back home.

Best Regards,
sephe

Actions #13

Updated by qhwt+dfly about 16 years ago

Yes, uploaded on my leaf account as ~y0netan1/crash/{kernel,vmcore}.11 .

Regards.

Actions #14

Updated by sepherosa about 16 years ago

On Tue, Mar 18, 2008 at 10:54 AM, YONETANI Tomokazu
<> wrote:

This panic is not what I had expected though :) Could you get a coredump?

Yes, uploaded on my leaf account as ~y0netan1/crash/{kernel,vmcore}.11 .

The cause of this panic probably is same as previous one.
Please test/review following patch:
http://leaf.dragonflybsd.org/~sephe/free_rtentry.diff

I also wipe out route entry in in_pcbladdr() if error happens and
route is allocated in this function.

Best Regards,
sephe

Actions #15

Updated by sepherosa about 16 years ago

Later this morning I noticed that sending datagram on unconnected UDP
socket and then connecting the UDP socket will cause same problem. So
for UDP, PRU_CONNECT will be dispatched according to addr+port pair,
please test/review following patch:
http://leaf.dragonflybsd.org/~sephe/free_rtentry1.diff

Best Regards,
sephe

Actions #16

Updated by sepherosa about 16 years ago

If no objection comes, I am going to commit this patch next week

Best Regards,
sephe

Actions #17

Updated by qhwt+dfly about 16 years ago

So far I haven't been able to reproduce the panic, and didn't notice
any other issues on patched system yet.

Cheers.

Actions

Also available in: Atom PDF