Re: [PATCH] kmemleak: Increase maximum early log entries to 1000000
On Wed, Jul 24, 2019 at 2:01 AM Andrey Ryabinin wrote:
>
>
>
> On 7/23/19 11:13 AM, Nicolas Boichat wrote:
> > On Tue, Jul 23, 2019 at 3:46 PM Dmitry Vyukov wrote:
> >>
> >> On Tue, Jul 23, 2019 at 9:26 AM Nicolas Boichat
> >> wrote:
> >>>
> >>> When KASan is enabled, a lot of memory is allocated early on,
> >>> and kmemleak complains (this is on a 4GB RAM system):
> >>> kmemleak: Early log buffer exceeded (129846), please increase
> >>> DEBUG_KMEMLEAK_EARLY_LOG_SIZE
> >>>
> >>> Let's increase the upper limit to 1M entry. That would take up
> >>> 160MB of RAM at init (each early_log entry is 160 bytes), but
> >>> the memory would later be freed (early_log is __initdata).
> >>
> >> Interesting. Is it on an arm64 system?
> >
> > Yes arm64. And this is chromiumos-4.19 tree. I didn't try to track
> > down where these allocations come from...
> >
>
> Is this still a problem in upstream tree? 4.19 doesn't have fed84c785270
> ("mm/memblock.c: skip kmemleak for kasan_init()")
Sorry for the delay, and thanks for the hint, indeed, not a problem
with that patch backported to our 4.19 tree: the number of allocations
shrinks from 100K+ to 1K+.
However, I think Dmitry is still right that the default (400) is too
low, I will send a patch for that.
Re: [PATCH] kmemleak: Increase maximum early log entries to 1000000
On 7/23/19 11:13 AM, Nicolas Boichat wrote:
> On Tue, Jul 23, 2019 at 3:46 PM Dmitry Vyukov wrote:
>>
>> On Tue, Jul 23, 2019 at 9:26 AM Nicolas Boichat
>> wrote:
>>>
>>> When KASan is enabled, a lot of memory is allocated early on,
>>> and kmemleak complains (this is on a 4GB RAM system):
>>> kmemleak: Early log buffer exceeded (129846), please increase
>>> DEBUG_KMEMLEAK_EARLY_LOG_SIZE
>>>
>>> Let's increase the upper limit to 1M entry. That would take up
>>> 160MB of RAM at init (each early_log entry is 160 bytes), but
>>> the memory would later be freed (early_log is __initdata).
>>
>> Interesting. Is it on an arm64 system?
>
> Yes arm64. And this is chromiumos-4.19 tree. I didn't try to track
> down where these allocations come from...
>
Is this still a problem in upstream tree? 4.19 doesn't have fed84c785270
("mm/memblock.c: skip kmemleak for kasan_init()")
Re: [PATCH] kmemleak: Increase maximum early log entries to 1000000
On Wed, Jul 24, 2019 at 12:17 AM Doug Anderson wrote: > > Hi, > > On Tue, Jul 23, 2019 at 1:21 AM Dmitry Vyukov wrote: > > > > On Tue, Jul 23, 2019 at 10:13 AM Nicolas Boichat > > wrote: > > > > > > On Tue, Jul 23, 2019 at 3:46 PM Dmitry Vyukov wrote: > > > > > > > > On Tue, Jul 23, 2019 at 9:26 AM Nicolas Boichat > > > > wrote: > > > > > > > > > > When KASan is enabled, a lot of memory is allocated early on, > > > > > and kmemleak complains (this is on a 4GB RAM system): > > > > > kmemleak: Early log buffer exceeded (129846), please increase > > > > > DEBUG_KMEMLEAK_EARLY_LOG_SIZE > > > > > > > > > > Let's increase the upper limit to 1M entry. That would take up > > > > > 160MB of RAM at init (each early_log entry is 160 bytes), but > > > > > the memory would later be freed (early_log is __initdata). > > > > > > > > Interesting. Is it on an arm64 system? > > > > > > Yes arm64. And this is chromiumos-4.19 tree. I didn't try to track > > > down where these allocations come from... > > > > So perhaps it's due to arm64, or you have even more configs, or maybe > > running on real hardware. But I guess it's fine as is, just wondered > > why such a radical difference. Thanks. > > If I had to guess I'd guess gcc vs. clang. I think we've noticed a > few places where clang+kasan produces much bloatier code than > gcc+kasan. Oh look, I just invented a new word: bloatier. :-P > > ...could you try building with gcc and see if that explains the problems? Just in case, there is no problem per se. There is just a difference :) Whom have you asked? We use gcc with KEMEMLEAK atm. But compiler should not affect number of kernel heap allocations.
Re: [PATCH] kmemleak: Increase maximum early log entries to 1000000
Hi, On Tue, Jul 23, 2019 at 1:21 AM Dmitry Vyukov wrote: > > On Tue, Jul 23, 2019 at 10:13 AM Nicolas Boichat > wrote: > > > > On Tue, Jul 23, 2019 at 3:46 PM Dmitry Vyukov wrote: > > > > > > On Tue, Jul 23, 2019 at 9:26 AM Nicolas Boichat > > > wrote: > > > > > > > > When KASan is enabled, a lot of memory is allocated early on, > > > > and kmemleak complains (this is on a 4GB RAM system): > > > > kmemleak: Early log buffer exceeded (129846), please increase > > > > DEBUG_KMEMLEAK_EARLY_LOG_SIZE > > > > > > > > Let's increase the upper limit to 1M entry. That would take up > > > > 160MB of RAM at init (each early_log entry is 160 bytes), but > > > > the memory would later be freed (early_log is __initdata). > > > > > > Interesting. Is it on an arm64 system? > > > > Yes arm64. And this is chromiumos-4.19 tree. I didn't try to track > > down where these allocations come from... > > So perhaps it's due to arm64, or you have even more configs, or maybe > running on real hardware. But I guess it's fine as is, just wondered > why such a radical difference. Thanks. If I had to guess I'd guess gcc vs. clang. I think we've noticed a few places where clang+kasan produces much bloatier code than gcc+kasan. Oh look, I just invented a new word: bloatier. :-P ...could you try building with gcc and see if that explains the problems? -Doug
Re: [PATCH] kmemleak: Increase maximum early log entries to 1000000
On Tue, Jul 23, 2019 at 10:13 AM Nicolas Boichat wrote:
>
> On Tue, Jul 23, 2019 at 3:46 PM Dmitry Vyukov wrote:
> >
> > On Tue, Jul 23, 2019 at 9:26 AM Nicolas Boichat
> > wrote:
> > >
> > > When KASan is enabled, a lot of memory is allocated early on,
> > > and kmemleak complains (this is on a 4GB RAM system):
> > > kmemleak: Early log buffer exceeded (129846), please increase
> > > DEBUG_KMEMLEAK_EARLY_LOG_SIZE
> > >
> > > Let's increase the upper limit to 1M entry. That would take up
> > > 160MB of RAM at init (each early_log entry is 160 bytes), but
> > > the memory would later be freed (early_log is __initdata).
> >
> > Interesting. Is it on an arm64 system?
>
> Yes arm64. And this is chromiumos-4.19 tree. I didn't try to track
> down where these allocations come from...
So perhaps it's due to arm64, or you have even more configs, or maybe
running on real hardware. But I guess it's fine as is, just wondered
why such a radical difference. Thanks.
> Slightly redacted dmesg until the error message:
> [0.00] Booting Linux on physical CPU 0x00 [0x410fd034]
> [0.00] Linux version 4.19.59 (drinkcat@X) (Chromium OS
> 9.0_pre361749_p20190714-r2 clang version 9.0.0
> (/var/cache/chromeos-cache/distfiles/host/egit-src/llvm-project
> c11de5eada2decd0a495ea02676b6f4838cd54fb) (based on LLVM 9.0.0svn)) #7
> SMP PREEMPT Tue Jul 23 16:00:50 CST 2019
> [0.00] Machine model: XYZ
> [0.00] Malformed early option 'console'
> [0.00] Reserved memory: created DMA memory pool at
> 0x5000, size 41 MiB
> [0.00] OF: reserved mem: initialized node scp_mem_region,
> compatible id shared-dma-pool
> [0.00] On node 0 totalpages: 1031920
> [0.00] DMA32 zone: 12288 pages used for memmap
> [0.00] DMA32 zone: 0 pages reserved
> [0.00] DMA32 zone: 769776 pages, LIFO batch:63
> [0.00] Normal zone: 4096 pages used for memmap
> [0.00] Normal zone: 262144 pages, LIFO batch:63
> [0.00] kmemleak: Kernel memory leak detector disabled
> [0.00] kasan: KernelAddressSanitizer initialized
> [0.00] psci: probing for conduit method from DT.
> [0.00] psci: PSCIv1.1 detected in firmware.
> [0.00] psci: Using standard PSCI v0.2 function IDs
> [0.00] psci: MIGRATE_INFO_TYPE not supported.
> [0.00] psci: SMC Calling Convention v1.1
> [0.00] random: get_random_bytes called from
> start_kernel+0x8c/0x384 with crng_init=0
> [0.00] percpu: Embedded 32 pages/cpu s92904 r8192 d29976 u131072
> [0.00] pcpu-alloc: s92904 r8192 d29976 u131072 alloc=32*4096
> [0.00] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 [0] 4 [0] 5 [0] 6 [0] 7
> [0.00] Detected VIPT I-cache on CPU0
> [0.00] CPU features: enabling workaround for ARM erratum 845719
> [0.00] Speculative Store Bypass Disable mitigation not required
> [0.00] CPU features: detected: Kernel page table isolation (KPTI)
> [0.00] Built 1 zonelists, mobility grouping on. Total pages: 1015536
> [0.00] Kernel command line: cros_secure cros_secure console=
> loglevel=7 init=/sbin/init cros_secure
> root=PARTUUID=45e54c6a-06a8-374c-a934-a07e23b37225/PARTNROFF=1
> rootwait rw dm_verity.error_behavior=3 dm_verity.max_bios=-1
> dm_verity.dev_wait=0 dm="1 vroot none ro 1,0 4710400 verity
> payload=ROOT_DEV hashtree=HASH_DEV hashstart=4710400 alg=sha256
> root_hexdigest=443fe95947f3b3f3cb54a10a53a4c7bb600ea1dd26d002066821236efa2419f4
> salt=ba17ba7736672036f119b0c925aa43e10ae1a960591a5b8bc85b21c166a49132"
> noinitrd cros_debug vt.global_cursor_default=0
> kern_guid=45e54c6a-06a8-374c-a934-a07e23b37225
> [0.00] device-mapper: init: will configure 1 devices
> [0.00] Dentry cache hash table entries: 524288 (order: 10,
> 4194304 bytes)
> [0.00] Inode-cache hash table entries: 262144 (order: 9, 2097152
> bytes)
> [0.00] software IO TLB: mapped [mem 0xfbdff000-0xffdff000] (64MB)
> [0.00] Memory: 3439892K/4127680K available (9726K kernel code,
> 1106K rwdata, 3064K rodata, 4096K init, 8893K bss, 687788K reserved,
> 0K cma-reserved)
> [0.00] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=8, Nodes=1
> [0.00] ftrace: allocating 34965 entries in 137 pages
> [0.00] rcu: Preemptible hierarchical RCU implementation.
> [0.00] Tasks RCU enabled.
> [0.00] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
> [0.00] GICv3: GIC: Using split EOI/Deactivate mode
> [0.00] GICv3: Distributor has no Range Selector support
> [0.00] GICv3: no VLPI support, no direct LPI support
> [0.00] GICv3: CPU0: found redistributor 0 region 0:0x0c10
> [0.00] GICv3: GIC: PPI partition interrupt-partition-0[0] {
> /cpus/cpu@0[0] /cpus/cpu@1[1] /cpus/cpu@2[2] /cpus/cpu@3[3] }
> [0.00] GICv3: GIC: PPI partition interrupt-partition-1[1] {
> /cpus/cpu@100[4] /cpus/cpu@101[5]
Re: [PATCH] kmemleak: Increase maximum early log entries to 1000000
On Tue, Jul 23, 2019 at 3:46 PM Dmitry Vyukov wrote:
>
> On Tue, Jul 23, 2019 at 9:26 AM Nicolas Boichat wrote:
> >
> > When KASan is enabled, a lot of memory is allocated early on,
> > and kmemleak complains (this is on a 4GB RAM system):
> > kmemleak: Early log buffer exceeded (129846), please increase
> > DEBUG_KMEMLEAK_EARLY_LOG_SIZE
> >
> > Let's increase the upper limit to 1M entry. That would take up
> > 160MB of RAM at init (each early_log entry is 160 bytes), but
> > the memory would later be freed (early_log is __initdata).
>
> Interesting. Is it on an arm64 system?
Yes arm64. And this is chromiumos-4.19 tree. I didn't try to track
down where these allocations come from...
Slightly redacted dmesg until the error message:
[0.00] Booting Linux on physical CPU 0x00 [0x410fd034]
[0.00] Linux version 4.19.59 (drinkcat@X) (Chromium OS
9.0_pre361749_p20190714-r2 clang version 9.0.0
(/var/cache/chromeos-cache/distfiles/host/egit-src/llvm-project
c11de5eada2decd0a495ea02676b6f4838cd54fb) (based on LLVM 9.0.0svn)) #7
SMP PREEMPT Tue Jul 23 16:00:50 CST 2019
[0.00] Machine model: XYZ
[0.00] Malformed early option 'console'
[0.00] Reserved memory: created DMA memory pool at
0x5000, size 41 MiB
[0.00] OF: reserved mem: initialized node scp_mem_region,
compatible id shared-dma-pool
[0.00] On node 0 totalpages: 1031920
[0.00] DMA32 zone: 12288 pages used for memmap
[0.00] DMA32 zone: 0 pages reserved
[0.00] DMA32 zone: 769776 pages, LIFO batch:63
[0.00] Normal zone: 4096 pages used for memmap
[0.00] Normal zone: 262144 pages, LIFO batch:63
[0.00] kmemleak: Kernel memory leak detector disabled
[0.00] kasan: KernelAddressSanitizer initialized
[0.00] psci: probing for conduit method from DT.
[0.00] psci: PSCIv1.1 detected in firmware.
[0.00] psci: Using standard PSCI v0.2 function IDs
[0.00] psci: MIGRATE_INFO_TYPE not supported.
[0.00] psci: SMC Calling Convention v1.1
[0.00] random: get_random_bytes called from
start_kernel+0x8c/0x384 with crng_init=0
[0.00] percpu: Embedded 32 pages/cpu s92904 r8192 d29976 u131072
[0.00] pcpu-alloc: s92904 r8192 d29976 u131072 alloc=32*4096
[0.00] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 [0] 4 [0] 5 [0] 6 [0] 7
[0.00] Detected VIPT I-cache on CPU0
[0.00] CPU features: enabling workaround for ARM erratum 845719
[0.00] Speculative Store Bypass Disable mitigation not required
[0.00] CPU features: detected: Kernel page table isolation (KPTI)
[0.00] Built 1 zonelists, mobility grouping on. Total pages: 1015536
[0.00] Kernel command line: cros_secure cros_secure console=
loglevel=7 init=/sbin/init cros_secure
root=PARTUUID=45e54c6a-06a8-374c-a934-a07e23b37225/PARTNROFF=1
rootwait rw dm_verity.error_behavior=3 dm_verity.max_bios=-1
dm_verity.dev_wait=0 dm="1 vroot none ro 1,0 4710400 verity
payload=ROOT_DEV hashtree=HASH_DEV hashstart=4710400 alg=sha256
root_hexdigest=443fe95947f3b3f3cb54a10a53a4c7bb600ea1dd26d002066821236efa2419f4
salt=ba17ba7736672036f119b0c925aa43e10ae1a960591a5b8bc85b21c166a49132"
noinitrd cros_debug vt.global_cursor_default=0
kern_guid=45e54c6a-06a8-374c-a934-a07e23b37225
[0.00] device-mapper: init: will configure 1 devices
[0.00] Dentry cache hash table entries: 524288 (order: 10,
4194304 bytes)
[0.00] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
[0.00] software IO TLB: mapped [mem 0xfbdff000-0xffdff000] (64MB)
[0.00] Memory: 3439892K/4127680K available (9726K kernel code,
1106K rwdata, 3064K rodata, 4096K init, 8893K bss, 687788K reserved,
0K cma-reserved)
[0.00] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=8, Nodes=1
[0.00] ftrace: allocating 34965 entries in 137 pages
[0.00] rcu: Preemptible hierarchical RCU implementation.
[0.00] Tasks RCU enabled.
[0.00] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[0.00] GICv3: GIC: Using split EOI/Deactivate mode
[0.00] GICv3: Distributor has no Range Selector support
[0.00] GICv3: no VLPI support, no direct LPI support
[0.00] GICv3: CPU0: found redistributor 0 region 0:0x0c10
[0.00] GICv3: GIC: PPI partition interrupt-partition-0[0] {
/cpus/cpu@0[0] /cpus/cpu@1[1] /cpus/cpu@2[2] /cpus/cpu@3[3] }
[0.00] GICv3: GIC: PPI partition interrupt-partition-1[1] {
/cpus/cpu@100[4] /cpus/cpu@101[5] /cpus/cpu@102[6] /cpus/cpu@103[7] }
[0.00] arch_timer: cp15 timer(s) running at 13.00MHz (phys).
[0.00] clocksource: arch_sys_counter: mask: 0xff
max_cycles: 0x2ff89eacb, max_idle_ns: 440795202429 ns
[0.03] sched_clock: 56 bits at 13MHz, resolution 76ns, wraps
every 4398046511101ns
[0.000441] kmemleak: Early log buffer exceeded (131217), please
increase
Re: [PATCH] kmemleak: Increase maximum early log entries to 1000000
On Tue, Jul 23, 2019 at 9:26 AM Nicolas Boichat wrote: > > When KASan is enabled, a lot of memory is allocated early on, > and kmemleak complains (this is on a 4GB RAM system): > kmemleak: Early log buffer exceeded (129846), please increase > DEBUG_KMEMLEAK_EARLY_LOG_SIZE > > Let's increase the upper limit to 1M entry. That would take up > 160MB of RAM at init (each early_log entry is 160 bytes), but > the memory would later be freed (early_log is __initdata). Interesting. Is it on an arm64 system? On syzbot we use 16000 and it's enough for a very beefy config: https://github.com/google/syzkaller/blob/master/dashboard/config/upstream-leak.config If it's freed later, I would increase the default as well. 400 never worked for me and I've seen people being confused and wasn't able to use kmemleak, e.g.: https://groups.google.com/forum/#!searchin/syzkaller/CONFIG_DEBUG_KMEMLEAK_EARLY_LOG_SIZE|sort:date/syzkaller/Rzf2ZRC9Qxw/tLog4DHXAgAJ https://groups.google.com/forum/#!searchin/syzkaller/CONFIG_DEBUG_KMEMLEAK_EARLY_LOG_SIZE|sort:date/syzkaller/5HxmTuQ7U4A/XM8s2o2CCAAJ > Signed-off-by: Nicolas Boichat > --- > lib/Kconfig.debug | 2 +- > 1 file changed, 1 insertion(+), 1 deletion(-) > > diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug > index f567875b87657de..1a197b8125768b9 100644 > --- a/lib/Kconfig.debug > +++ b/lib/Kconfig.debug > @@ -595,7 +595,7 @@ config DEBUG_KMEMLEAK > config DEBUG_KMEMLEAK_EARLY_LOG_SIZE > int "Maximum kmemleak early log entries" > depends on DEBUG_KMEMLEAK > - range 200 4 > + range 200 100 > default 400 > help > Kmemleak must track all the memory allocations to avoid > -- > 2.22.0.657.g960e92d24f-goog >
