Bug 120691 - UART HCI memory leak
Summary: UART HCI memory leak
Status: RESOLVED PATCH_ALREADY_AVAILABLE
Alias: None
Product: Drivers
Classification: Unclassified
Component: Bluetooth (show other bugs)
Hardware: ARM Linux
: P1 normal
Assignee: linux-bluetooth@vger.kernel.org
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-06-20 13:46 UTC by nico.edev
Modified: 2016-08-23 09:35 UTC (History)
5 users (show)

See Also:
Kernel Version: 4.7-rc3
Subsystem:
Regression: No
Bisected commit-id:


Attachments
Test Patch (812 bytes, patch)
2016-07-10 03:12 UTC, [account disabled by administrator]
Details | Diff
kmemleak_csr8510a10 (78.19 KB, text/plain)
2016-08-04 14:52 UTC, Nicolas Royer
Details
kmemleak_bcm4343w (1.23 MB, text/plain)
2016-08-04 14:53 UTC, Nicolas Royer
Details
Bluetooth Test Patch (955 bytes, patch)
2016-08-07 00:58 UTC, [account disabled by administrator]
Details | Diff

Description nico.edev 2016-06-20 13:46:40 UTC
Hello,

It looks like there is a memory leak on UART HCI driver. I am using kernel 4.7-rc3 and Bluez 5.40. I can reproduce the issue with kernel 4.2.
There is nothing special to do to encounter the problem; HCI traffic is enough.
I can speed up the occurrence of the issue when BT module is scanning because it increases HCI traffic.
My BT module is dual mode but I can reproduce the issue when I force "brerd" or "le" mode.
FYI, the leak is 1MByte/hour when BT scanning is on; which is a lot on embedded systems.

Below is a piece of kmemleak dump:

unreferenced object 0xc6a59ac0 (size 2048):
  comm "kworker/u2:0", pid 6, jiffies 4294951225 (age 1195.920s)
  hex dump (first 32 bytes):
    6b 6b 6b 6b 6b 6b 6b 6b 0e 0e 01 04 10 00 01 01  kkkkkkkk........
    00 00 00 00 00 00 00 00 6b 6b 6b 6b 6b 6b 6b 6b  ........kkkkkkkk
  backtrace:
    [<c03c93a0>] __alloc_skb+0x7c/0x164
    [<c03563ac>] ll_recv+0x1c8/0x41c
    [<c03554b4>] hci_uart_tty_receive+0x44/0x64
    [<c0255ec4>] tty_ldisc_receive_buf+0x50/0x58
    [<c0256338>] flush_to_ldisc+0xb8/0xd0
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
unreferenced object 0xc62f0020 (size 168):
  comm "kworker/u3:2", pid 439, jiffies 4294951225 (age 1195.920s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 54 a4 46 a9 95 53 54 14  ........T.F..ST.
    00 00 00 00 00 00 00 00 04 00 00 00 01 00 00 00  ................
  backtrace:
    [<c0473bfc>] hci_event_packet+0x1d8/0x2ba0
    [<c04674c8>] hci_rx_work+0x170/0x248
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
unreferenced object 0xc6a5be40 (size 2048):
  comm "kworker/u2:0", pid 6, jiffies 4294951227 (age 1195.900s)
  hex dump (first 32 bytes):
    6b 6b 6b 6b 6b 6b 6b 6b 0e 04 01 10 20 00 6b 6b  kkkkkkkk.... .kk
    6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
  backtrace:
    [<c03c93a0>] __alloc_skb+0x7c/0x164
    [<c03563ac>] ll_recv+0x1c8/0x41c
    [<c03554b4>] hci_uart_tty_receive+0x44/0x64
    [<c0255ec4>] tty_ldisc_receive_buf+0x50/0x58
    [<c0256338>] flush_to_ldisc+0xb8/0xd0
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
unreferenced object 0xc6315da0 (size 168):
  comm "kworker/u3:2", pid 439, jiffies 4294951227 (age 1195.900s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 5d c6 6d aa 95 53 54 14  ........].m..ST.
    00 00 00 00 00 00 00 00 04 00 00 00 01 00 00 00  ................
  backtrace:
    [<c0473bfc>] hci_event_packet+0x1d8/0x2ba0
    [<c04674c8>] hci_rx_work+0x170/0x248
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
unreferenced object 0xc6a5a3a0 (size 2048):
  comm "kworker/u2:0", pid 6, jiffies 4294951228 (age 1195.890s)
  hex dump (first 32 bytes):
    6b 6b 6b 6b 6b 6b 6b 6b 0e 06 01 12 0c 00 00 00  kkkkkkkk........
    6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
  backtrace:
    [<c03c93a0>] __alloc_skb+0x7c/0x164
    [<c03563ac>] ll_recv+0x1c8/0x41c
    [<c03554b4>] hci_uart_tty_receive+0x44/0x64
    [<c0255ec4>] tty_ldisc_receive_buf+0x50/0x58
    [<c0256338>] flush_to_ldisc+0xb8/0xd0
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
unreferenced object 0xc6315620 (size 168):
  comm "kworker/u3:2", pid 439, jiffies 4294951228 (age 1195.890s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 1a 97 8f aa 95 53 54 14  .............ST.
    00 00 00 00 00 00 00 00 04 00 00 00 01 00 00 00  ................
  backtrace:
    [<c0473bfc>] hci_event_packet+0x1d8/0x2ba0
    [<c04674c8>] hci_rx_work+0x170/0x248
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
unreferenced object 0xc63151a0 (size 168):
  comm "kworker/u3:0", pid 435, jiffies 4294953313 (age 1175.050s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 86 3f ce 85 9a 53 54 14  .........?...ST.
    00 00 00 00 00 00 00 00 04 00 00 00 01 00 00 00  ................
  backtrace:
    [<c0473bfc>] hci_event_packet+0x1d8/0x2ba0
    [<c04674c8>] hci_rx_work+0x170/0x248
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
unreferenced object 0xc6a5ac80 (size 2048):
  comm "kworker/u2:0", pid 6, jiffies 4294958830 (age 1119.880s)
  hex dump (first 32 bytes):
    6b 6b 6b 6b 6b 6b 6b 6b 0e 0a 01 09 10 00 f8 a7  kkkkkkkk........
    d7 e9 17 00 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  ....kkkkkkkkkkkk
  backtrace:
    [<c03c93a0>] __alloc_skb+0x7c/0x164
    [<c03563ac>] ll_recv+0x1c8/0x41c
    [<c03554b4>] hci_uart_tty_receive+0x44/0x64
    [<c0255ec4>] tty_ldisc_receive_buf+0x50/0x58
    [<c0256338>] flush_to_ldisc+0xb8/0xd0
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
unreferenced object 0xc6315aa0 (size 168):
  comm "kworker/u3:2", pid 439, jiffies 4294958830 (age 1119.890s)
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 c0 e0 d1 5d a7 53 54 14  ...........].ST.
    00 00 00 00 00 00 00 00 04 00 00 00 01 00 00 00  ................
  backtrace:
    [<c0473bfc>] hci_event_packet+0x1d8/0x2ba0
    [<c04674c8>] hci_rx_work+0x170/0x248
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
unreferenced object 0xc6600020 (size 2048):
  comm "kworker/u2:0", pid 6, jiffies 4294958833 (age 1119.860s)
  hex dump (first 32 bytes):
    6b 6b 6b 6b 6b 6b 6b 6b 0e 0e 01 04 10 00 01 01  kkkkkkkk........
    01 00 00 00 00 00 00 00 6b 6b 6b 6b 6b 6b 6b 6b  ........kkkkkkkk
  backtrace:
    [<c03c93a0>] __alloc_skb+0x7c/0x164
    [<c03563ac>] ll_recv+0x1c8/0x41c
    [<c03554b4>] hci_uart_tty_receive+0x44/0x64
    [<c0255ec4>] tty_ldisc_receive_buf+0x50/0x58
    [<c0256338>] flush_to_ldisc+0xb8/0xd0
    [<c00318c0>] process_one_work+0x128/0x478
    [<c0031c64>] worker_thread+0x54/0x574
    [<c00368f4>] kthread+0xc0/0xdc
    [<c000a2d0>] ret_from_fork+0x14/0x24
    [<ffffffff>] 0xffffffff
...

I had a look to kernel source code but did not find anything obvious.

Thanks!
Comment 1 Loic Poulain 2016-06-22 10:00:48 UTC
Seems that this memory leak is due to the hci_ll (TI) proto.
Don't think this comes from the generic hci-uart/ldisc part.
To be sure, are you able to reproduce this issue with any other proto (hci_h4, hci_bcm, hci_intel..)?
Comment 2 nico.edev 2016-06-22 16:38:30 UTC
Unfortunately my BT module only support TI protocol and I don't have another one.
Comment 3 [account disabled by administrator] 2016-07-10 03:11:41 UTC
Try the below attached patch.
Comment 4 [account disabled by administrator] 2016-07-10 03:12:01 UTC
Created attachment 222571 [details]
Test Patch
Comment 5 [account disabled by administrator] 2016-07-19 20:57:27 UTC
Are you able to post the object kmemleak is complaining about at that particular address.
Comment 6 nico.edev 2016-07-20 08:06:10 UTC
I did not see your post and now I am in business trip. I will try next week and let you know.
Thanks a lot.
Comment 7 nico.edev 2016-08-01 15:55:20 UTC
I tried the patch but problem is still there.
Comment 8 [account disabled by administrator] 2016-08-01 17:35:39 UTC
Can you enable kmemleak and use the documentation here to find out what object is leaking,https://www.kernel.org/doc/Documentation/kmemleak.txt.
Comment 9 Nicolas Royer 2016-08-04 13:57:04 UTC
I finally got BT modules with BT controller from Broadcom (BCM4343W: UART H4) and CSR (CSR8510A10: USB).

The leak is present whatever the controller.
In all cases kmemleak reports leaks in the BT controller driver (hci_ll, hci_h4, btusb) but also in hci_event.

It looks like the leak is in the HCI layer. I will try to figure out what object is leaking in hci_event.

Below are kmemleak logs for BCM4343W and CSR8510A10.
Comment 10 Nicolas Royer 2016-08-04 14:52:49 UTC
Created attachment 227531 [details]
kmemleak_csr8510a10
Comment 11 Nicolas Royer 2016-08-04 14:53:37 UTC
Created attachment 227541 [details]
kmemleak_bcm4343w
Comment 12 [account disabled by administrator] 2016-08-07 00:58:25 UTC
See if the below patch fixes or does something new in terms of kmemleak warning(s) you are getting from these bluetooth drivers.
Comment 13 [account disabled by administrator] 2016-08-07 00:58:46 UTC
Created attachment 227881 [details]
Bluetooth Test Patch
Comment 14 [account disabled by the administrator] 2016-08-17 21:30:02 UTC
Can you see if that patch fixed the issue or do I need to write a new one.
Comment 15 Nicolas Royer 2016-08-22 12:39:34 UTC
Unfortunately the leak is still there.
Comment 16 [account disabled by the administrator] 2016-08-22 14:18:29 UTC
Seems someone else has fixed this and moved it upstream so just close this bug.
Comment 17 nico.edev 2016-08-23 09:35:52 UTC
Exactly; I tried this patch and the leak disappeared: http://marc.info/?l=linux-bluetooth&m=147193208628547

Note You need to log in before you can comment on or make changes to this bug.