Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1465190 > unrolled thread

[PATCH] proc, smaps: reduce printing overhead

Started byMichal Hocko <mhocko@kernel.org>
First post2016-08-18 13:40 +0200
Last post2016-08-23 18:20 +0200
Articles 4 on this page of 24 — 2 participants

Back to article view | Back to linux.kernel


Contents

  [PATCH] proc, smaps: reduce printing overhead Michal Hocko <mhocko@kernel.org> - 2016-08-18 13:40 +0200
    Re: [PATCH] proc, smaps: reduce printing overhead Joe Perches <joe@perches.com> - 2016-08-18 15:30 +0200
      Re: [PATCH] proc, smaps: reduce printing overhead Joe Perches <joe@perches.com> - 2016-08-18 16:50 +0200
      Re: [PATCH] proc, smaps: reduce printing overhead Joe Perches <joe@perches.com> - 2016-08-18 16:50 +0200
        Re: [PATCH] proc, smaps: reduce printing overhead Joe Perches <joe@perches.com> - 2016-08-19 03:00 +0200
          Re: [PATCH] proc, smaps: reduce printing overhead Michal Hocko <mhocko@kernel.org> - 2016-08-19 03:40 +0200
        Re: [PATCH] proc, smaps: reduce printing overhead Michal Hocko <mhocko@kernel.org> - 2016-08-19 06:00 +0200
      Re: [PATCH] proc, smaps: reduce printing overhead Michal Hocko <mhocko@kernel.org> - 2016-08-18 16:50 +0200
        Re: [PATCH] proc, smaps: reduce printing overhead Michal Hocko <mhocko@kernel.org> - 2016-08-18 16:50 +0200
    [PATCH 2/2] proc, smaps: reduce printing overhead Michal Hocko <mhocko@kernel.org> - 2016-08-19 12:20 +0200
    [PATCH 1/2] proc, meminfo: abstract show_val_kb Michal Hocko <mhocko@kernel.org> - 2016-08-19 12:20 +0200
    [PATCH 0/2] fs, proc: optimize smaps output formatting Michal Hocko <mhocko@kernel.org> - 2016-08-19 12:20 +0200
      Re: [PATCH 0/2] fs, proc: optimize smaps output formatting Joe Perches <joe@perches.com> - 2016-08-19 19:50 +0200
        Re: [PATCH 0/2] fs, proc: optimize smaps output formatting Joe Perches <joe@perches.com> - 2016-08-19 22:20 +0200
        Re: [PATCH 0/2] fs, proc: optimize smaps output formatting Michal Hocko <mhocko@kernel.org> - 2016-08-20 09:30 +0200
          Re: [PATCH 0/2] fs, proc: optimize smaps output formatting Joe Perches <joe@perches.com> - 2016-08-20 10:00 +0200
          [PATCH 0/2] seq: Speed up /proc/<pid>/smaps Joe Perches <joe@perches.com> - 2016-08-20 10:10 +0200
          [PATCH 1/2] seq_file: Add __seq_open_private_bufsize for seq file_operation sizes Joe Perches <joe@perches.com> - 2016-08-20 10:10 +0200
          [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time Joe Perches <joe@perches.com> - 2016-08-20 10:10 +0200
            Re: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time Michal Hocko <mhocko@kernel.org> - 2016-08-22 09:30 +0200
              Re: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time Joe Perches <joe@perches.com> - 2016-08-22 10:10 +0200
                Re: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time Joe Perches <joe@perches.com> - 2016-08-22 10:40 +0200
                  Re: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time Michal Hocko <mhocko@kernel.org> - 2016-08-22 14:10 +0200
    Re: [PATCH] proc, smaps: reduce printing overhead Michal Hocko <mhocko@kernel.org> - 2016-08-23 18:20 +0200

Page 2 of 2 — ← Prev page 1 [2]


#1467437 — Re: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time

FromJoe Perches <joe@perches.com>
Date2016-08-22 10:10 +0200
SubjectRe: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time
Message-ID<s8SsV-3Ku-3@gated-at.bofh.it>
In reply to#1467417
On Mon, 2016-08-22 at 09:24 +0200, Michal Hocko wrote:
> On Sat 20-08-16 01:00:17, Joe Perches wrote:
> [...]
> > 
> >  static int proc_maps_open(struct inode *inode, struct file *file,
> >  			const struct seq_operations *ops, int psize)
> >  {
> > -	struct proc_maps_private *priv = __seq_open_private(file, ops, psize);
> > +	struct proc_maps_private *priv;
> > +	struct mm_struct *mm;
> > +
> > +	mm = proc_mem_open(inode, PTRACE_MODE_READ);
> > +	if (IS_ERR(mm))
> > +		return PTR_ERR(mm);
> >  
> > +	priv = __seq_open_private_bufsize(file, ops, psize,
> > +					  mm && mm->map_count ?
> > +					  mm->map_count * 0x300 : PAGE_SIZE);
> NAK to this!
>
> Seriously, this just gives any random user access to user
> defined amount of memory which not accounted, not reclaimable and a
> potential consumer of any higher order blocks.

I completely disagree here with your rationale here.

I think you didn't read the code and didn't try it either.

This code is identical to the previous code but it
simply estimates the required output size first.

> Besides that, at least one show_smap output will always fit inside the
> single page and AFAIR (it's been quite a while since I've looked into
> seq_file internals) the buffer grows only when the single show doesn't
> fit in.

It's never been like that as far as I know.

Please read fs/seq_file.c:traverse()

This code starts with a PAGE_SIZE block of memory then if
the complete output doesn't fit, stops, frees that block
of memory, and retries the complete output with a last block
size allocated << 1 and tries again.

> I really do not understand why you insist on code duplication rather
> than reuse but if you really insist then just make this (without the
> above __seq_open_private_bufsize, re-measure and add the results to the
> changelog and repost.

I've tried it, I wish you would.

[toc] | [prev] | [next] | [standalone]


#1467456 — Re: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time

FromJoe Perches <joe@perches.com>
Date2016-08-22 10:40 +0200
SubjectRe: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time
Message-ID<s8SVX-3V6-1@gated-at.bofh.it>
In reply to#1467437
On Mon, 2016-08-22 at 01:00 -0700, Joe Perches wrote:
> On Mon, 2016-08-22 at 09:24 +0200, Michal Hocko wrote:
> > On Sat 20-08-16 01:00:17, Joe Perches wrote:
[]
> > > static int proc_maps_open(struct inode *inode, struct file *file,
> > >  			const struct seq_operations *ops, int psize)
> > >  {
> > > -	struct proc_maps_private *priv = __seq_open_private(file, ops, psize);
> > > +	struct proc_maps_private *priv;
> > > +	struct mm_struct *mm;
> > > +
> > > +	mm = proc_mem_open(inode, PTRACE_MODE_READ);
> > > +	if (IS_ERR(mm))
> > > +		return PTR_ERR(mm);
> > >  
> > > +	priv = __seq_open_private_bufsize(file, ops, psize,
> > > +					  mm && mm->map_count ?
> > > +					  mm->map_count * 0x300 : PAGE_SIZE);
> > NAK to this!
> > 
> > Seriously, this just gives any random user access to user
> > defined amount of memory which not accounted, not reclaimable and a
> > potential consumer of any higher order blocks.
> I completely disagree here with your rationale here.

And with further review and your comment above, I withdraw this patch.
cheers, Joe

[toc] | [prev] | [next] | [standalone]


#1467573 — Re: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time

FromMichal Hocko <mhocko@kernel.org>
Date2016-08-22 14:10 +0200
SubjectRe: [PATCH 2/2] proc: task_mmu: Reduce output processing cpu time
Message-ID<s8Wdc-66j-19@gated-at.bofh.it>
In reply to#1467456
On Mon 22-08-16 01:30:14, Joe Perches wrote:
> On Mon, 2016-08-22 at 01:00 -0700, Joe Perches wrote:
> > On Mon, 2016-08-22 at 09:24 +0200, Michal Hocko wrote:
> > > On Sat 20-08-16 01:00:17, Joe Perches wrote:
> []
> > > > static int proc_maps_open(struct inode *inode, struct file *file,
> > > >  			const struct seq_operations *ops, int psize)
> > > >  {
> > > > -	struct proc_maps_private *priv = __seq_open_private(file, ops, psize);
> > > > +	struct proc_maps_private *priv;
> > > > +	struct mm_struct *mm;
> > > > +
> > > > +	mm = proc_mem_open(inode, PTRACE_MODE_READ);
> > > > +	if (IS_ERR(mm))
> > > > +		return PTR_ERR(mm);
> > > >  
> > > > +	priv = __seq_open_private_bufsize(file, ops, psize,
> > > > +					  mm && mm->map_count ?
> > > > +					  mm->map_count * 0x300 : PAGE_SIZE);
> > > NAK to this!
> > > 
> > > Seriously, this just gives any random user access to user
> > > defined amount of memory which not accounted, not reclaimable and a
> > > potential consumer of any higher order blocks.
> > I completely disagree here with your rationale here.
> 
> And with further review and your comment above, I withdraw this patch.

So you've made me look into that code. I can imagine how it is easy to
to get confused here. The important part is that m->count is reset after
each ->show(). So traverse() same as seq_read only grows the buffer if
a single show doesn't fit in.

That being said, should I repost my rebased patches or do you plan to
repost your patch? I do not want spam people with another version if
you do not like it.
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [next] | [standalone]


#1468680

FromMichal Hocko <mhocko@kernel.org>
Date2016-08-23 18:20 +0200
Message-ID<s9mAG-6kW-27@gated-at.bofh.it>
In reply to#1465190
On Thu 18-08-16 13:31:28, Michal Hocko wrote:
> From: Michal Hocko <mhocko@suse.com>
> 
> seq_printf (used by show_smap) can be pretty expensive when dumping a
> lot of numbers.  Say we would like to get Rss and Pss from a particular
> process.  In order to measure a pathological case let's generate as many
> mappings as possible:
> 
> $ cat max_mmap.c
> int main()
> {
> 	while (mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_ANON|MAP_SHARED|MAP_POPULATE, -1, 0) != MAP_FAILED)
> 		;
> 
> 	printf("pid:%d\n", getpid());
> 	pause();
> 	return 0;
> }
> 
> $ awk '/^Rss/{rss+=$2} /^Pss/{pss+=$2} END {printf "rss:%d pss:%d\n", rss, pss}' /proc/$pid/smaps
> 
> would do a trick. The whole runtime is in the kernel space which is not
> that that unexpected because smaps is not the cheapest one (we have to
> do rmap walk etc.).
> 
>         Command being timed: "awk /^Rss/{rss+=$2} /^Pss/{pss+=$2} END {printf "rss:%d pss:%d\n", rss, pss} /proc/3050/smaps"
>         User time (seconds): 0.01
>         System time (seconds): 0.44
>         Percent of CPU this job got: 99%
>         Elapsed (wall clock) time (h:mm:ss or m:ss): 0:00.47
> 
> But the perf says:
>     22.55%  awk      [kernel.kallsyms]  [k] format_decode
>     14.65%  awk      [kernel.kallsyms]  [k] vsnprintf
>      6.40%  awk      [kernel.kallsyms]  [k] number
>      2.53%  awk      [kernel.kallsyms]  [k] shmem_mapping
>      2.53%  awk      [kernel.kallsyms]  [k] show_smap
>      1.81%  awk      [kernel.kallsyms]  [k] lock_acquire
> 
> we are spending most of the time actually generating the output which is
> quite lame. Let's replace seq_printf by seq_puts and seq_put_decimal_ull.
> This will give us:
>         Command being timed: "awk /^Rss/{rss+=$2} /^Pss/{pss+=$2} END {printf "rss:%d pss:%d\n", rss, pss} /proc/3067/smaps"
>         User time (seconds): 0.00
>         System time (seconds): 0.41
>         Percent of CPU this job got: 99%
>         Elapsed (wall clock) time (h:mm:ss or m:ss): 0:00.42
> 
> which will give us ~7% improvement. Perf says:
>     28.87%  awk      [kernel.kallsyms]  [k] seq_puts
>      5.30%  awk      [kernel.kallsyms]  [k] vsnprintf
>      4.54%  awk      [kernel.kallsyms]  [k] format_decode
>      3.73%  awk      [kernel.kallsyms]  [k] show_smap
>      2.56%  awk      [kernel.kallsyms]  [k] shmem_mapping
>      1.92%  awk      [kernel.kallsyms]  [k] number
>      1.80%  awk      [kernel.kallsyms]  [k] lock_acquire
>      1.75%  awk      [kernel.kallsyms]  [k] print_name_value_kb

OK, so it turned out that I was fooled by VIRT_CPU_ACCOUNTING_GEN
accounting [1]. So I have replaced it by TICK_CPU_ACCOUNTING and the
numbers the seq_printf -> seq_write doesn't seem to be all that much of
a win.
Before
        User time (seconds): 0.14
        System time (seconds): 0.30
        Percent of CPU this job got: 98%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:00.45

    19.66%  awk      [kernel.kallsyms]  [k] format_decode
    14.25%  awk      [kernel.kallsyms]  [k] vsnprintf
     6.42%  awk      [kernel.kallsyms]  [k] number
     2.88%  awk      mawk               [.] 0x0000000000006910
     2.58%  awk      [kernel.kallsyms]  [k] shmem_mapping
     2.12%  awk      mawk               [.] 0x0000000000006918
     2.02%  awk      [kernel.kallsyms]  [k] show_smap

after:
        User time (seconds): 0.13
        System time (seconds): 0.31
        Percent of CPU this job got: 99%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:00.45

    23.89%  awk      [kernel.kallsyms]  [k] seq_write
     5.84%  awk      [kernel.kallsyms]  [k] vsnprintf
     5.08%  awk      [kernel.kallsyms]  [k] format_decode
     4.00%  awk      [kernel.kallsyms]  [k] show_val_kb
     3.84%  awk      [kernel.kallsyms]  [k] show_smap
     2.16%  awk      [kernel.kallsyms]  [k] number
     2.05%  awk      [kernel.kallsyms]  [k] shmem_mapping

so it is basically in noise.

[1] http://lkml.kernel.org/r/20160823143330.GL23577@dhcp22.suse.cz
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [standalone]


Page 2 of 2 — ← Prev page 1 [2]

Back to top | Article view | linux.kernel


csiph-web