Message ID | 20220225180318.20594-6-vbabka@suse.cz (mailing list archive) |
---|---|
State | New |
Headers | show |
Series | SLUB debugfs improvements based on stackdepot | expand |
On Fri, Feb 25, 2022 at 07:03:18PM +0100, Vlastimil Babka wrote: > From: Oliver Glitta <glittao@gmail.com> > > Add description of debugfs files alloc_traces and free_traces > to SLUB cache documentation. > > [ vbabka@suse.cz: some rewording ] > > Signed-off-by: Oliver Glitta <glittao@gmail.com> > Signed-off-by: Vlastimil Babka <vbabka@suse.cz> > Cc: Jonathan Corbet <corbet@lwn.net> > Cc: Randy Dunlap <rdunlap@infradead.org> > Cc: linux-doc@vger.kernel.org > --- > Documentation/vm/slub.rst | 61 +++++++++++++++++++++++++++++++++++++++ > 1 file changed, 61 insertions(+) > > diff --git a/Documentation/vm/slub.rst b/Documentation/vm/slub.rst > index d3028554b1e9..2b2b931e59fc 100644 > --- a/Documentation/vm/slub.rst > +++ b/Documentation/vm/slub.rst > @@ -384,5 +384,66 @@ c) Execute ``slabinfo-gnuplot.sh`` in '-t' mode, passing all of the > 40,60`` range will plot only samples collected between 40th and > 60th seconds). > > + > +DebugFS files for SLUB > +====================== > + > +For more information about current state of SLUB caches with the user tracking > +debug option enabled, debugfs files are available, typically under > +/sys/kernel/debug/slab/<cache>/ (created only for caches with enabled user > +tracking). There are 2 types of these files with the following debug > +information: > + > +1. alloc_traces:: > + > + Prints information about unique allocation traces of the currently > + allocated objects. The output is sorted by frequency of each trace. > + > + Information in the output: > + Number of objects, allocating function, minimal/average/maximal jiffies since alloc, > + pid range of the allocating processes, cpu mask of allocating cpus, and stack trace. > + > + Example::: > + > + 1085 populate_error_injection_list+0x97/0x110 age=166678/166680/166682 pid=1 cpus=1:: > + __slab_alloc+0x6d/0x90 > + kmem_cache_alloc_trace+0x2eb/0x300 > + populate_error_injection_list+0x97/0x110 > + init_error_injection+0x1b/0x71 > + do_one_initcall+0x5f/0x2d0 > + kernel_init_freeable+0x26f/0x2d7 > + kernel_init+0xe/0x118 > + ret_from_fork+0x22/0x30 > + > + > +2. free_traces:: > + > + Prints information about unique free traces of the currently free objects, > + sorted by their frequency. > + I'm not sure that it's traces of the "currently free objects". static int slab_debug_trace_open(struct inode *inode, struct file *filep) { [...] obj_map = bitmap_alloc(oo_objects(s->oo), GFP_KERNEL); [...] for_each_kmem_cache_node(s, node, n) { unsigned long flags; struct slab *slab; if (!atomic_long_read(&n->nr_slabs)) continue; spin_lock_irqsave(&n->list_lock, flags); list_for_each_entry(slab, &n->partial, slab_list) process_slab(t, s, slab, alloc, obj_map); list_for_each_entry(slab, &n->full, slab_list) process_slab(t, s, slab, alloc, obj_map); spin_unlock_irqrestore(&n->list_lock, flags); } [...] } static void __fill_map(unsigned long *obj_map, struct kmem_cache *s, struct slab *slab) { void *addr = slab_address(slab); void *p; bitmap_zero(obj_map, slab->objects); for (p = slab->freelist; p; p = get_freepointer(s, p)) set_bit(__obj_to_index(s, addr, p), obj_map); } static void process_slab(struct loc_track *t, struct kmem_cache *s, struct slab *slab, enum track_item alloc, unsigned long *obj_map) { void *addr = slab_address(slab); void *p; __fill_map(obj_map, s, slab); for_each_object(p, s, addr, slab->objects) if (!test_bit(__obj_to_index(s, addr, p), obj_map)) add_location(t, s, get_track(s, p, alloc)); } I think it's not traces of "currently free objects" because index bit of free objects are set in obj_map bitmap? It's weird but it's traces of allocated objects that have been freed at least once (or <not available>) I think we can fix the code or doc? Please tell me if I'm missing something :) > + Information in the output: > + Number of objects, freeing function, minimal/average/maximal jiffies since free, > + pid range of the freeing processes, cpu mask of freeing cpus, and stack trace. > + > + Example::: > + > + 51 acpi_ut_update_ref_count+0x6a6/0x782 age=236886/237027/237772 pid=1 cpus=1 > + kfree+0x2db/0x420 > + acpi_ut_update_ref_count+0x6a6/0x782 > + acpi_ut_update_object_reference+0x1ad/0x234 > + acpi_ut_remove_reference+0x7d/0x84 > + acpi_rs_get_prt_method_data+0x97/0xd6 > + acpi_get_irq_routing_table+0x82/0xc4 > + acpi_pci_irq_find_prt_entry+0x8e/0x2e0 > + acpi_pci_irq_lookup+0x3a/0x1e0 > + acpi_pci_irq_enable+0x77/0x240 > + pcibios_enable_device+0x39/0x40 > + do_pci_enable_device.part.0+0x5d/0xe0 > + pci_enable_device_flags+0xfc/0x120 > + pci_enable_device+0x13/0x20 > + virtio_pci_probe+0x9e/0x170 > + local_pci_probe+0x48/0x80 > + pci_device_probe+0x105/0x1c0 > + Everything else looks nice! > Christoph Lameter, May 30, 2007 > Sergey Senozhatsky, October 23, 2015 > -- > 2.35.1 > >
On 2/27/22 04:49, Hyeonggon Yoo wrote: > I think it's not traces of "currently free objects" > because index bit of free objects are set in obj_map bitmap? Hm right, thanks. > It's weird but it's traces of allocated objects that have been freed at > least once (or <not available>) > > I think we can fix the code or doc? For now I'll fix the doc. Not clear to me myself what's the best usecase for free_traces file. For alloc_traces it's clearly debugging memory leaks. Freeing traces are most useful when a bug is detected and they are dumped in dmesg. The debugfs file might be just for a rough idea where freeing usually happens. > Please tell me if I'm missing something :) > >> + Information in the output: >> + Number of objects, freeing function, minimal/average/maximal jiffies since free, >> + pid range of the freeing processes, cpu mask of freeing cpus, and stack trace. >> + >> + Example::: >> + >> + 51 acpi_ut_update_ref_count+0x6a6/0x782 age=236886/237027/237772 pid=1 cpus=1 >> + kfree+0x2db/0x420 >> + acpi_ut_update_ref_count+0x6a6/0x782 >> + acpi_ut_update_object_reference+0x1ad/0x234 >> + acpi_ut_remove_reference+0x7d/0x84 >> + acpi_rs_get_prt_method_data+0x97/0xd6 >> + acpi_get_irq_routing_table+0x82/0xc4 >> + acpi_pci_irq_find_prt_entry+0x8e/0x2e0 >> + acpi_pci_irq_lookup+0x3a/0x1e0 >> + acpi_pci_irq_enable+0x77/0x240 >> + pcibios_enable_device+0x39/0x40 >> + do_pci_enable_device.part.0+0x5d/0xe0 >> + pci_enable_device_flags+0xfc/0x120 >> + pci_enable_device+0x13/0x20 >> + virtio_pci_probe+0x9e/0x170 >> + local_pci_probe+0x48/0x80 >> + pci_device_probe+0x105/0x1c0 >> + > > Everything else looks nice! > >> Christoph Lameter, May 30, 2007 >> Sergey Senozhatsky, October 23, 2015 >> -- >> 2.35.1 >> >> >
diff --git a/Documentation/vm/slub.rst b/Documentation/vm/slub.rst index d3028554b1e9..2b2b931e59fc 100644 --- a/Documentation/vm/slub.rst +++ b/Documentation/vm/slub.rst @@ -384,5 +384,66 @@ c) Execute ``slabinfo-gnuplot.sh`` in '-t' mode, passing all of the 40,60`` range will plot only samples collected between 40th and 60th seconds). + +DebugFS files for SLUB +====================== + +For more information about current state of SLUB caches with the user tracking +debug option enabled, debugfs files are available, typically under +/sys/kernel/debug/slab/<cache>/ (created only for caches with enabled user +tracking). There are 2 types of these files with the following debug +information: + +1. alloc_traces:: + + Prints information about unique allocation traces of the currently + allocated objects. The output is sorted by frequency of each trace. + + Information in the output: + Number of objects, allocating function, minimal/average/maximal jiffies since alloc, + pid range of the allocating processes, cpu mask of allocating cpus, and stack trace. + + Example::: + + 1085 populate_error_injection_list+0x97/0x110 age=166678/166680/166682 pid=1 cpus=1:: + __slab_alloc+0x6d/0x90 + kmem_cache_alloc_trace+0x2eb/0x300 + populate_error_injection_list+0x97/0x110 + init_error_injection+0x1b/0x71 + do_one_initcall+0x5f/0x2d0 + kernel_init_freeable+0x26f/0x2d7 + kernel_init+0xe/0x118 + ret_from_fork+0x22/0x30 + + +2. free_traces:: + + Prints information about unique free traces of the currently free objects, + sorted by their frequency. + + Information in the output: + Number of objects, freeing function, minimal/average/maximal jiffies since free, + pid range of the freeing processes, cpu mask of freeing cpus, and stack trace. + + Example::: + + 51 acpi_ut_update_ref_count+0x6a6/0x782 age=236886/237027/237772 pid=1 cpus=1 + kfree+0x2db/0x420 + acpi_ut_update_ref_count+0x6a6/0x782 + acpi_ut_update_object_reference+0x1ad/0x234 + acpi_ut_remove_reference+0x7d/0x84 + acpi_rs_get_prt_method_data+0x97/0xd6 + acpi_get_irq_routing_table+0x82/0xc4 + acpi_pci_irq_find_prt_entry+0x8e/0x2e0 + acpi_pci_irq_lookup+0x3a/0x1e0 + acpi_pci_irq_enable+0x77/0x240 + pcibios_enable_device+0x39/0x40 + do_pci_enable_device.part.0+0x5d/0xe0 + pci_enable_device_flags+0xfc/0x120 + pci_enable_device+0x13/0x20 + virtio_pci_probe+0x9e/0x170 + local_pci_probe+0x48/0x80 + pci_device_probe+0x105/0x1c0 + Christoph Lameter, May 30, 2007 Sergey Senozhatsky, October 23, 2015