kmemleak report in 3.9.5+, related to cfg80211_inform_bss_frame

DISCUSSION Ben Greear 2 participants 6 messages Jun 11, 2013 – Jun 15, 2013

Share & tools

Ben Greear

author

2013-06-11 19:00 UTC #0 lore raw

I see several reports similar to the one below while doing some kmemleak testing on my 3.9.5+ tree (with local patches applied):

http://dmz2.candelatech.com/git/gitweb.cgi?p=linux-3.9.dev.y/.git;a=summary

While looking through the code, I found this in scan.c:cfg80211_bss_update

		} else {
			/*
			 * Ok so we found a beacon, and don't have an entry. If
			 * it's a beacon with hidden SSID, we might be in for an
			 * expensive search for any probe responses that should
			 * be grouped with this beacon for updates ...
			 */
			if (!cfg80211_combine_bsses(dev, new)) {
				kfree(new);
				goto drop;
			}
		}

I don't know if this is the culprit that I am seeing, but I believe we should be freeing the tmp.pub.beacon_ies (if it is not NULL) before doing the 'goto drop'?

The kmemleak report is below:

unreferenced object 0xffff8801c8e41e78 (size 192):
comm "kworker/u:2", pid 157, jiffies 4295509873 (age 86582.869s) hex dump (first 32 bytes):

    41 0d 00 30 02 00 00 00 6b 6b 6b 6b 6b 6b 6b 6b  A..0....kkkkkkkk
    6b 6b 6b 6b 6b 6b 6b 6b 69 00 00 00 00 0c 2e 32  kkkkkkkki......2
  backtrace:
    [<ffffffff815de7bf>] kmemleak_alloc+0x73/0x98
    [<ffffffff8118b4d4>] slab_post_alloc_hook+0x28/0x2a
    [<ffffffff8118d605>] __kmalloc+0xf9/0x122
    [<ffffffffa027cb27>] cfg80211_inform_bss_frame+0x114/0x1f8 [cfg80211]
    [<ffffffffa03d6865>] ieee80211_bss_info_update+0x66/0x21f [mac80211]
    [<ffffffffa040aec6>] ieee80211_rx_bss_info+0x12f/0x1ca [mac80211]
    [<ffffffffa040b017>] ieee80211_rx_mgmt_probe_resp+0xb6/0x197 [mac80211]
    [<ffffffffa040e8a3>] ieee80211_sta_rx_queued_mgmt+0xdd/0x60e [mac80211]
    [<ffffffffa03df0ee>] ieee80211_iface_work+0x238/0x2cc [mac80211]
    [<ffffffff810b0cd3>] process_one_work+0x292/0x42e
    [<ffffffff810b36af>] worker_thread+0x14f/0x264
    [<ffffffff810b7bea>] kthread+0xc7/0xcf
    [<ffffffff815f64ec>] ret_from_fork+0x7c/0xb0
    [<ffffffffffffffff>] 0xffffffffffffffff

(gdb) l *(cfg80211_inform_bss_frame+0x114)
0x8b27 is in cfg80211_inform_bss_frame (/home/greearb/git/linux-3.9.dev.y/net/wireless/scan.c:960).
955 ielen, channel);
956 if (!channel)
957 return NULL;
958
959 ies = kmalloc(sizeof(*ies) + ielen, gfp);
960 if (!ies)
961 return NULL;
962 ies->len = ielen;
963 ies->tsf = le64_to_cpu(mgmt->u.probe_resp.timestamp);
964 memcpy(ies->data, mgmt->u.probe_resp.variable, ielen);
(gdb)

Thanks,
Ben

Signature · 2 lines

Ben Greear <[email protected]>
Candela Technologies Inc  http://www.candelatech.com

Ben Greear

author

2013-06-11 19:08 UTC #1 lore raw

Quoted 21 lines · Ben Greear

I see several reports similar to the one below while doing some kmemleak testing on my 3.9.5+ tree (with local patches applied):
http://dmz2.candelatech.com/git/gitweb.cgi?p=linux-3.9.dev.y/.git;a=summary
While looking through the code, I found this in scan.c:cfg80211_bss_update
         } else {
             /*
              * Ok so we found a beacon, and don't have an entry. If
              * it's a beacon with hidden SSID, we might be in for an
              * expensive search for any probe responses that should
              * be grouped with this beacon for updates ...
              */
             if (!cfg80211_combine_bsses(dev, new)) {
                 kfree(new);
                 goto drop;
             }
         }

Quoted 3 lines

I don't know if this is the culprit that I am seeing, but I believe we should be freeing the tmp.pub.beacon_ies (if it is not NULL) before doing the 'goto drop'?

Err, I guess not. Seems the only way that combine_bsses can return false is if beacon_ies is null. So, I guess it must be something else...

Quoted 46 lines

The kmemleak report is below:

unreferenced object 0xffff8801c8e41e78 (size 192):

   comm "kworker/u:2", pid 157, jiffies 4295509873 (age 86582.869s)
   hex dump (first 32 bytes):
     41 0d 00 30 02 00 00 00 6b 6b 6b 6b 6b 6b 6b 6b  A..0....kkkkkkkk
     6b 6b 6b 6b 6b 6b 6b 6b 69 00 00 00 00 0c 2e 32  kkkkkkkki......2
   backtrace:
     [<ffffffff815de7bf>] kmemleak_alloc+0x73/0x98
     [<ffffffff8118b4d4>] slab_post_alloc_hook+0x28/0x2a
     [<ffffffff8118d605>] __kmalloc+0xf9/0x122
     [<ffffffffa027cb27>] cfg80211_inform_bss_frame+0x114/0x1f8 [cfg80211]
     [<ffffffffa03d6865>] ieee80211_bss_info_update+0x66/0x21f [mac80211]
     [<ffffffffa040aec6>] ieee80211_rx_bss_info+0x12f/0x1ca [mac80211]
     [<ffffffffa040b017>] ieee80211_rx_mgmt_probe_resp+0xb6/0x197 [mac80211]
     [<ffffffffa040e8a3>] ieee80211_sta_rx_queued_mgmt+0xdd/0x60e [mac80211]
     [<ffffffffa03df0ee>] ieee80211_iface_work+0x238/0x2cc [mac80211]
     [<ffffffff810b0cd3>] process_one_work+0x292/0x42e
     [<ffffffff810b36af>] worker_thread+0x14f/0x264
     [<ffffffff810b7bea>] kthread+0xc7/0xcf
     [<ffffffff815f64ec>] ret_from_fork+0x7c/0xb0
     [<ffffffffffffffff>] 0xffffffffffffffff

962        ies->len = ielen;
963        ies->tsf = le64_to_cpu(mgmt->u.probe_resp.timestamp);
964        memcpy(ies->data, mgmt->u.probe_resp.variable, ielen);

(gdb)

Thanks,
Ben

Signature · 2 lines

Ben Greear <[email protected]>
Candela Technologies Inc  http://www.candelatech.com

Ben Greear

author

2013-06-12 00:36 UTC #2 lore raw

Quoted 21 lines · Ben Greear

Quoted 20 lines · Ben Greear
I see several reports similar to the one below while doing some kmemleak testing on my 3.9.5+ tree (with local patches applied):
http://dmz2.candelatech.com/git/gitweb.cgi?p=linux-3.9.dev.y/.git;a=summary
The kmemleak report is below:
unreferenced object 0xffff8801c8e41e78 (size 192):
   comm "kworker/u:2", pid 157, jiffies 4295509873 (age 86582.869s)
   hex dump (first 32 bytes):
     41 0d 00 30 02 00 00 00 6b 6b 6b 6b 6b 6b 6b 6b  A..0....kkkkkkkk
     6b 6b 6b 6b 6b 6b 6b 6b 69 00 00 00 00 0c 2e 32  kkkkkkkki......2
   backtrace:
     [<ffffffff815de7bf>] kmemleak_alloc+0x73/0x98
     [<ffffffff8118b4d4>] slab_post_alloc_hook+0x28/0x2a
     [<ffffffff8118d605>] __kmalloc+0xf9/0x122
     [<ffffffffa027cb27>] cfg80211_inform_bss_frame+0x114/0x1f8 [cfg80211]
     [<ffffffffa03d6865>] ieee80211_bss_info_update+0x66/0x21f [mac80211]
     [<ffffffffa040aec6>] ieee80211_rx_bss_info+0x12f/0x1ca [mac80211]

Quoted 8 lines

     [<ffffffffa040b017>] ieee80211_rx_mgmt_probe_resp+0xb6/0x197 [mac80211]
     [<ffffffffa040e8a3>] ieee80211_sta_rx_queued_mgmt+0xdd/0x60e [mac80211]
     [<ffffffffa03df0ee>] ieee80211_iface_work+0x238/0x2cc [mac80211]
     [<ffffffff810b0cd3>] process_one_work+0x292/0x42e
     [<ffffffff810b36af>] worker_thread+0x14f/0x264
     [<ffffffff810b7bea>] kthread+0xc7/0xcf
     [<ffffffff815f64ec>] ret_from_fork+0x7c/0xb0
     [<ffffffffffffffff>] 0xffffffffffffffff

Something else came to mind on this.

To determine if we should delete an old pointer to memory, we do an rcu_access_pointer to read the old value, and we are assigning with rcu_assign_pointer.

Could this be racing so that rcu_access_pointer returns NULL when looking for the old pointer, but other threads manage to set the pointer more than once, leaking all but the last to be set?

For instance, this code:

	if (found) {
		/* Update IEs */
		if (rcu_access_pointer(tmp->pub.proberesp_ies)) {
			const struct cfg80211_bss_ies *old;

			old = rcu_access_pointer(found->pub.proberesp_ies);

			rcu_assign_pointer(found->pub.proberesp_ies,
					   tmp->pub.proberesp_ies);
			/* Override possible earlier Beacon frame IEs */
			rcu_assign_pointer(found->pub.ies,
					   tmp->pub.proberesp_ies);
			if (old)
				kfree_rcu((struct cfg80211_bss_ies *)old,
					  rcu_head);

I don't see a huge number of leaks..but they are definitely accumulating if kmemleak is to be believed...

Thanks,
Ben

Signature · 2 lines

Ben Greear <[email protected]>
Candela Technologies Inc  http://www.candelatech.com

Ben Greear

author

2013-06-14 22:48 UTC #3 lore raw

Quoted 22 lines · Ben Greear

Quoted 21 lines · Ben Greear
Quoted 20 lines · Ben Greear
I see several reports similar to the one below while doing some kmemleak testing on my 3.9.5+ tree (with local patches applied):
http://dmz2.candelatech.com/git/gitweb.cgi?p=linux-3.9.dev.y/.git;a=summary
The kmemleak report is below:
unreferenced object 0xffff8801c8e41e78 (size 192):
   comm "kworker/u:2", pid 157, jiffies 4295509873 (age 86582.869s)
   hex dump (first 32 bytes):
     41 0d 00 30 02 00 00 00 6b 6b 6b 6b 6b 6b 6b 6b  A..0....kkkkkkkk
     6b 6b 6b 6b 6b 6b 6b 6b 69 00 00 00 00 0c 2e 32  kkkkkkkki......2
   backtrace:
     [<ffffffff815de7bf>] kmemleak_alloc+0x73/0x98
     [<ffffffff8118b4d4>] slab_post_alloc_hook+0x28/0x2a
     [<ffffffff8118d605>] __kmalloc+0xf9/0x122
     [<ffffffffa027cb27>] cfg80211_inform_bss_frame+0x114/0x1f8 [cfg80211]
     [<ffffffffa03d6865>] ieee80211_bss_info_update+0x66/0x21f [mac80211]
     [<ffffffffa040aec6>] ieee80211_rx_bss_info+0x12f/0x1ca [mac80211]

Quoted 8 lines

     [<ffffffffa040b017>] ieee80211_rx_mgmt_probe_resp+0xb6/0x197 [mac80211]
     [<ffffffffa040e8a3>] ieee80211_sta_rx_queued_mgmt+0xdd/0x60e [mac80211]
     [<ffffffffa03df0ee>] ieee80211_iface_work+0x238/0x2cc [mac80211]
     [<ffffffff810b0cd3>] process_one_work+0x292/0x42e
     [<ffffffff810b36af>] worker_thread+0x14f/0x264
     [<ffffffff810b7bea>] kthread+0xc7/0xcf
     [<ffffffff815f64ec>] ret_from_fork+0x7c/0xb0
     [<ffffffffffffffff>] 0xffffffffffffffff

I am still working on trying to figure this one out.

I've instrumented all (as far as I can tell) allocation points and destruction points for the ies, and I am keeping a separate list of structures to record some info about each ies.

I loaded up lots of stations, let them bounce around for a while, and then did an 'rmmod ath9k'.

I still see 14 ies entries in my debug list. Should I expect to see zero ies data structures left after I rmmod all wifi drivers, or is it normal for a few to be left around?

Thanks,
Ben

Signature · 2 lines

Ben Greear <[email protected]>
Candela Technologies Inc  http://www.candelatech.com

Johannes Berg

2013-06-15 17:11 UTC #4 lore raw

Quoted 11 lines · Ben Greear

I've instrumented all (as far as I can tell) allocation points and destruction points for the ies, and I am keeping a separate list of structures to record some info about each ies.
I loaded up lots of stations, let them bounce around for a while, and then did an 'rmmod ath9k'.
I still see 14 ies entries in my debug list. Should I expect to see zero ies data structures left after I rmmod all wifi drivers, or is it normal for a few to be left around?

No, that's decidedly not normal, but that's pretty much just what kmemleak already told us, no? Good to verify, but doesn't really help pinpoint the problem either, I'd say :-(

johannes

Ben Greear

author

2013-06-15 19:18 UTC #5 lore raw

Quoted 9 lines · Johannes Berg

Quoted 7 lines · Ben Greear
I've instrumented all (as far as I can tell) allocation points and destruction points for the ies, and I am keeping a separate list of structures to record some info about each ies.
I loaded up lots of stations, let them bounce around for a while, and then did an 'rmmod ath9k'.

Quoted 8 lines

Quoted 4 lines
I still see 14 ies entries in my debug list. Should I expect to see zero ies data structures left after I rmmod all wifi drivers, or is it normal for a few to be left around?
No, that's decidedly not normal, but that's pretty much just what kmemleak already told us, no? Good to verify, but doesn't really help pinpoint the problem either, I'd say :-(

Well, I wanted to make sure it wasn't false-positive in kmemleak.

Sometime around March someone reported a similar issue but decided kmemleak was wrong (and you fixed one corner case that was reported at the same time)..

I tried instrumenting the bss as well. From what I can tell, we are leaking them, as when I print out all bss for the phy* objects, I only get 14. But, I see several hundred that were allocated and never freed.

kmemleak didn't show leaked bss, so possibly I am wrong about this, or maybe they are still (properly?) referenced from the virtual station interfaces.

Is there any good reason that there would be a significant amount of bss objects in the system that are not in the bss_list for the wiphys?

This is from my debug code, but perhaps it gives an idea (actually, the ies are undercounted, as 31500 was the buffer size I allowed for debugfs...I'll work on better instrumentation to give an accurate count of still-allocated ies.)

[root@LEC2220-1 ~]# cat /debug/ieee80211/wiphy*/bss|wc

     14     112    1288
[root@LEC2220-1 ~]# cat /debug/ieee80211/ies |wc
    642    1286   31500
[root@LEC2220-1 ~]# cat /debug/ieee80211/all_bss|wc
    382     764   16044

The good news is that it appears the bss growth (at least) does not grow too fast..this is after around 20 hours of running the torture test that constantly is trying to (re)associate 400 stations with an AP that can handle only 127.

Thanks,
Ben

Quoted 3 lines

johannes

Signature · 2 lines

Ben Greear <[email protected]>
Candela Technologies Inc  http://www.candelatech.com