NULL pointer dereference at __ip_route_output_key

NULL pointer dereference at __ip_route_output_key

[Dave Jones]

We just had this reported. Look familiar to anyone ?

:BUG: unable to handle kernel NULL pointer dereference at 00000000000000d0
:IP: [<ffffffff81518d73>] __ip_route_output_key+0x703/0x9f0
:PGD 0 
:Oops: 0000 [#1] SMP 
:CPU 0 
:Modules linked in: fuse ppdev parport_pc lp parport ebtable_nat ebtables
ipt_MASQUERADE iptable_nat nf_nat xt_CHECKSUM iptable_mangle bridge stp llc
lockd be2iscsi iscsi_boot_sysfs bnx2i cnic uio cxgb4i cxgb4 cxgb3i libcxgbi
cxgb3 mdio ib_iser rdma_cm ib_cm iw_cm ib_sa ib_addr iscsi_tcp libiscsi_tcp
libiscsi scsi_transport_iscsi ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6
ip6table_filter nf_conntrack_ipv4 ip6_tables nf_defrag_ipv4 xt_state
nf_conntrack usblp joydev raid10 binfmt_misc snd_hda_codec_hdmi
snd_hda_codec_realtek microcode sp5100_tco snd_hda_intel k10temp snd_hda_codec
serio_raw i2c_piix4 snd_hwdep snd_seq edac_core vhost_net edac_mce_amd
snd_seq_device macvtap macvlan tun virtio_net snd_pcm ib_qib kvm_amd snd_timer
snd kvm r8169 ib_mad soundcore snd_page_alloc ib_core mii uinput sunrpc
firewire_ohci ata_generic firewire_core pata_acpi crc_itu_t pata_atiixp wmi
usb_storage radeon ttm drm_kms_helper drm i2c_algo_bit i2c_core [last unloaded:
scsi_wait_scan]
:Pid: 3269, comm: sendmail Not tainted 3.3.0-8.fc16.x86_64 #1 Gigabyte
Technology Co., Ltd. GA-MA790X-UD4/GA-MA790X-UD4
:RIP: 0010:[<ffffffff81518d73>]  [<ffffffff81518d73>]
__ip_route_output_key+0x703/0x9f0
:RSP: 0018:ffff880128be1da8  EFLAGS: 00010246
:RAX: 0000000000000000 RBX: ffff88010adda970 RCX: 0000000000000000
:RDX: 00000000017aa8c0 RSI: ffff880117ac2000 RDI: ffff880121ab6000
:RBP: ffff880128be1e38 R08: 0000000000000001 R09: 0000000000000000
:R10: ffff880123095480 R11: ffff880107e91b40 R12: 0000000000000000
:R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
:FS:  00007f4ad68ae7c0(0000) GS:ffff88012fc00000(0000) knlGS:0000000000000000
:CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
:CR2: 00000000000000d0 CR3: 0000000102ef1000 CR4: 00000000000006f0
:DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
:DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
:Process sendmail (pid: 3269, threadinfo ffff880128be0000, task
ffff88009e48c590)
:Stack:
: 00000000fe07dd09 ffff88010adda680 b7da880128be1ed0 ffffffff81544440
: ffffffff81f74200 f1281bd40adda680 ffff880128be1e38 0000000000010000
: ffff880107e91b40 ffff880123095480 ffff880123307698 ffff880129693540
:Call Trace:
: [<ffffffff81544440>] ? udp_lib_lport_inuse+0xf0/0xf0
: [<ffffffff81542717>] ip4_datagram_connect+0x167/0x300
: [<ffffffff8154fca1>] inet_dgram_connect+0x31/0x90
: [<ffffffff814d156b>] sys_connect+0xeb/0x110
: [<ffffffff8117f98b>] ? fd_install+0x3b/0x70
: [<ffffffff810d347c>] ? __audit_syscall_entry+0xcc/0x310
: [<ffffffff810d3a96>] ? __audit_syscall_exit+0x3d6/0x410
: [<ffffffff814d0e40>] ? sys_socket+0x40/0x70
: [<ffffffff815fbca9>] system_call_fastpath+0x16/0x1b
:Code: 01 7e 08 3c 01 0f 84 d7 02 00 00 8b 53 14 85 d2 0f 84 aa 01 00 00 0f b6
45 a9 48 8d 04 c0 44 0f b6 45 aa 45 31 ff 4d 8b 64 c3 60 <41> 8b 84 24 d0 00 00
00 89 03 0f b6 c2 e9 a7 fa ff ff 31 d2 44 


https://bugzilla.redhat.com/show_bug.cgi?id=808990

Re: NULL pointer dereference at __ip_route_output_key

[David Miller]

From: Dave Jones <davej@redhat.com>
Date: Mon, 2 Apr 2012 15:40:56 -0400

> We just had this reported. Look familiar to anyone ?

If you could unravel the source file and line the OOPS occurs at, I
can look at these kinds of reports much faster.  As it stands, when I
see a Fedora OOPS, it's a long process for me:

1) Edit /boot/vmlinuz-3.3.0-8, stip image until gzip header and
   store in x.gz, gzip -d x.gz

2) gdb ./x and try to match up symbols in System.map, which BTW
   I have to become root to even friggin' _READ_, and oh yes
   doubly stupid because there's a readable copy under /usr/src

3) Try to bisect where it's OOPS'ing in the source code, and given
   GCC's optimizations where it moves basic blocks all over the
   place, this is error prone and time consuming.

etc. etc.

Anyways in this case dev_out is NULL when we read it around line
2798 of net/ipv4/route.c:

	dev_out = FIB_RES_DEV(res);
	fl4->flowi4_oif = dev_out->ifindex;

and we are thus OOPS'ing on the dev_out->ifindex.

Unfortunately I've never seen a report like this.  If the reporter can
reproduce, you can try to extract more information by doing something
like this right after the dev_out assignment:

	if (!dev_out) {
		pr_crit("ipv4: FIB_RES_DEV() is NULL, nh_sel=%d\n",
			res.nh_sel);
		rth = ERR_PTR(-EINVAL);
		goto out;
	}

This debugging will also avoid the NULL pointer crash at least for
that particular invocation.

Re: NULL pointer dereference at __ip_route_output_key

[Dave Jones]

On Mon, Apr 02, 2012 at 08:07:11PM -0400, David Miller wrote:

 > > We just had this reported. Look familiar to anyone ?
 > 
 > If you could unravel the source file and line the OOPS occurs at, I
 > can look at these kinds of reports much faster.  As it stands, when I
 > see a Fedora OOPS, it's a long process for me:

Ok, I'll try and pull these apart for you in future, as I usually
have the bits for the most recent builds around. 

 > Anyways in this case dev_out is NULL when we read it around line
 > 2798 of net/ipv4/route.c:
 > 
 > 	dev_out = FIB_RES_DEV(res);
 > 	fl4->flowi4_oif = dev_out->ifindex;
 > 
 > and we are thus OOPS'ing on the dev_out->ifindex.
 > 
 > Unfortunately I've never seen a report like this.  If the reporter can
 > reproduce, you can try to extract more information by doing something
 > like this right after the dev_out assignment:
 > 
 > 	if (!dev_out) {
 > 		pr_crit("ipv4: FIB_RES_DEV() is NULL, nh_sel=%d\n",
 > 			res.nh_sel);
 > 		rth = ERR_PTR(-EINVAL);
 > 		goto out;
 > 	}
 > 
 > This debugging will also avoid the NULL pointer crash at least for
 > that particular invocation.

ok, I'll do a test build with this change for the user to try out.
Hopefully he can retrigger it.

thanks,

	Dave

Re: NULL pointer dereference at __ip_route_output_key

[David Miller]

From: Dave Jones <davej@redhat.com>
Date: Mon, 2 Apr 2012 20:22:00 -0400

> On Mon, Apr 02, 2012 at 08:07:11PM -0400, David Miller wrote:
> 
>  > > We just had this reported. Look familiar to anyone ?
>  > 
>  > If you could unravel the source file and line the OOPS occurs at, I
>  > can look at these kinds of reports much faster.  As it stands, when I
>  > see a Fedora OOPS, it's a long process for me:
> 
> Ok, I'll try and pull these apart for you in future, as I usually
> have the bits for the most recent builds around. 

Thanks a lot Dave.

Re: NULL pointer dereference at __ip_route_output_key

[Yevgen Pronenko]

Hello David,

> 2798 of net/ipv4/route.c:
>
>> dev_out = FIB_RES_DEV(res);
 >> fl4->flowi4_oif = dev_out->ifindex;
>
> and we are thus OOPS'ing on the dev_out->ifindex.
>
> Unfortunately I've never seen a report like this. If the reporter
> can reproduce, you can try to extract more information by doing
> something like this right after the dev_out assignment:

I observed a crash in exactly the same place recently.

wlan: disconnected
Unable to handle kernel NULL pointer dereference at virtual address 00000070
cfg80211: Calling CRDA to update world regulatory domain
pgd = d67a4000
[00000070] *pgd=9f144831, *pte=00000000, *ppte=00000000
Internal error: Oops: 17 [#1] PREEMPT SMP
Modules linked in: wlan(P) cfg80211 [last unloaded: wlan]
CPU: 0    Tainted: P        W    (3.0.8+1.0.21100-01783-gb40b976 #1)
PC is at __ip_route_output_key+0x49c/0x78c
LR is at fib_rules_lookup+0x16c/0x174
pc : [<c05fb848>]    lr : [<c05bcaf4>]    psr: 60000013
sp : d6899bb0  ip : d6899bc4  fp : 00000000
r10: 00000000  r9 : 00000000  r8 : 479047c2
r7 : 00000000  r6 : 00000000  r5 : d6899bc4  r4 : d6899c64
r3 : cdc04600  r2 : 0415c05e  r1 : cdc04600  r0 : fa2410ac
Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
Control: 10c5787d  Table: 9daa406a  DAC: 00000015
...
[<c05fb848>] (__ip_route_output_key+0x49c/0x78c) from [<c05fbb4c>] 
(ip_route_output_flow+0x14/0x50)
[<c05fbb4c>] (ip_route_output_flow+0x14/0x50) from [<c0623ff0>] 
(udp_sendmsg+0x358/0x72c)
[<c0623ff0>] (udp_sendmsg+0x358/0x72c) from [<c06701b4>] 
(udpv6_sendmsg+0x154/0x8d8)
[<c06701b4>] (udpv6_sendmsg+0x154/0x8d8) from [<c062b8a0>] 
(inet_sendmsg+0xac/0xb4)
[<c062b8a0>] (inet_sendmsg+0xac/0xb4) from [<c0597ed4>] 
(sock_sendmsg+0xa0/0xbc)
[<c0597ed4>] (sock_sendmsg+0xa0/0xbc) from [<c05985ec>] 
(sys_sendto+0xbc/0xfc)
[<c05985ec>] (sys_sendto+0xbc/0xfc) from [<c0105e60>] 
(ret_fast_syscall+0x0/0x30)

Analyzing the dump I found that FIB_RES_DEV(res) macros in the line 
mentioned above returned NULL.
I was able to dump a content of related structures in memory:

res: struct fib_result {
     prefixlen = 0 '\000',
     nh_sel = 0 '\000',
     type = 1 '\001',
     scope = 0 '\000',
     struct fib_info *fi = 0xcdc04600
         -> {
             fib_hash = {
                 next = 0x100100,
                 pprev = 0x200200
             },
             fib_lhash = {
                 next = 0x0,
                 pprev = 0x0
             },
             fib_net = 0xc0da8000,
             fib_treeref = 0,
             fib_clntref = {
                 counter = 0
             },
             fib_flags = 0,
             fib_dead = 1 '\001',
             fib_protocol = 3 '\003',
             fib_scope = 0 '\000',
             fib_prefsrc = 0,
             fib_priority = 314,
             fib_metrics = 0xc0da88a0,
             fib_nhs = 1,
             rcu = {
                 next = 0xc9df30e8,
                 func = 0x34
             },
             fib_nh = 0xcdc0463c
         }
     struct fib_table *table = 0xd88684c0
      -> {
             tb_hlist = {
                 next = 0x0,
                 pprev = 0xd9ab5bf8
             },
             tb_id = 254,
             tb_default = -1,
             tb_num_default = 1,
             tb_data = 0xd88684d4
         }
     struct list_head *fa_head = 0xd7e13554
      -> {
             next = 0xd7e13554,
             prev = 0xd7e13554
         }
     struct fib_rule *r = 0xd7e05300
      -> {
             list = {
                 next = 0xd7e05780,
                 prev = 0xd9b13500
             },
             refcnt = {
                 counter = 1
             },
             iifindex = 0,
             oifindex = 0,
             mark = 0,
             mark_mask = 0,
             pref = 32766,
             flags = 0,
             table = 254,
             action = 1 '\001',
             target = 0,
             ctarget = 0x0,
             iifname = 
"\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",
             oifname = 
"\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000",
             rcu = {
                 next = 0x0,
                 func = 0
             },
             fr_net = 0xc0da8000
         }
}

Here is the content of res.fi->fib_nh:

struct fib_nh {
     nh_dev = 0x0,
     nh_hash = {
         next = 0x100100,
         pprev = 0x200200
     },
     nh_parent = 0xcdc04600,
     nh_flags = 0,
     nh_scope = 253 '\375',
     nh_oif = 14,
     nh_gw = 18878636,
     nh_saddr = 4196667564,
     nh_saddr_genid = 68534366
}

As you can see, there is a NULL in res.fi->fib_nh.nh_dev. One more thing 
which looks suspicious for me is that res.fi->fib_dead is 1 here. And 
the crash happened just after shutting down a WLAN interface (the last 
string in the kernel log was "wlan: disconnected").

Having that, is it possible there is a race between network resources 
deallocation and a route lookup procedure?

The crash was observed only once and I am not able to reproduce it, but 
I have a crash dump, so I can grep it for additional information (kernel 
logs, values of variables, etc).

Here is the basic information about the system:
      RELEASE: 3.0.8+1.0.21100-01783-gb40b976
      VERSION: #1 SMP PREEMPT Thu Apr 12 06:19:58 2012
      MACHINE: armv7l  (unknown Mhz)


Yevgen Pronenko.

Re: NULL pointer dereference at __ip_route_output_key

[David Miller]

From: Yevgen Pronenko <yevgen.pronenko@sonymobile.com>
Date: Thu, 19 Apr 2012 16:58:52 +0200

> As you can see, there is a NULL in res.fi->fib_nh.nh_dev. One more
> thing which looks suspicious for me is that res.fi->fib_dead is 1
> here. And the crash happened just after shutting down a WLAN interface
> (the last string in the kernel log was "wlan: disconnected").
> 
> Having that, is it possible there is a race between network resources
> deallocation and a route lookup procedure?

Indeed this area is a mess.

Nothing actually gates on fi->fib_dead except for an assertion in
free_fib_info().

Therefore, fi->fib_dead is essentially useless, and doesn't block
usage of fib_info objects that we are about to liberate via RCU.

My initial impression is that we need to shift the cleanup code into
the RCU handler (free_fib_info_rcu), and add some checks on
fi->fib_dead to the fib_info lookup paths.

I suspect we might have lost the fi->fib_dead tests unintentionally
when we converted the fib_info lookup paths to be refcount-less and
use RCU.  Oddly enough, the code does check for things like
(fi->fib_flags & RTNH_F_DEAD).

Anyways, I'll do some data-mining to figure out what happened here
and then use that information to cons up a fix.

Thanks for the report.