Re: [PATCH 1/3] mm: page_alloc: Reduce object size by neatening printks

[Sergey Senozhatsky]

On (03/16/17 11:37), Joe Perches wrote:
> On Thu, 2017-03-16 at 20:30 +0900, Sergey Senozhatsky wrote:
> > On (03/15/17 18:43), Joe Perches wrote:
> > [..]
> > > -	printk("active_anon:%lu inactive_anon:%lu isolated_anon:%lu\n"
> > > -		" active_file:%lu inactive_file:%lu isolated_file:%lu\n"
> > > -		" unevictable:%lu dirty:%lu writeback:%lu unstable:%lu\n"
> > > -		" slab_reclaimable:%lu slab_unreclaimable:%lu\n"
> > > -		" mapped:%lu shmem:%lu pagetables:%lu bounce:%lu\n"
> > > -		" free:%lu free_pcp:%lu free_cma:%lu\n",
> > > -		global_node_page_state(NR_ACTIVE_ANON),
> > > -		global_node_page_state(NR_INACTIVE_ANON),
> > > -		global_node_page_state(NR_ISOLATED_ANON),
> > > -		global_node_page_state(NR_ACTIVE_FILE),
> > > -		global_node_page_state(NR_INACTIVE_FILE),
> > > -		global_node_page_state(NR_ISOLATED_FILE),
> > > -		global_node_page_state(NR_UNEVICTABLE),
> > > -		global_node_page_state(NR_FILE_DIRTY),
> > > -		global_node_page_state(NR_WRITEBACK),
> > > -		global_node_page_state(NR_UNSTABLE_NFS),
> > > -		global_page_state(NR_SLAB_RECLAIMABLE),
> > > -		global_page_state(NR_SLAB_UNRECLAIMABLE),
> > > -		global_node_page_state(NR_FILE_MAPPED),
> > > -		global_node_page_state(NR_SHMEM),
> > > -		global_page_state(NR_PAGETABLE),
> > > -		global_page_state(NR_BOUNCE),
> > > -		global_page_state(NR_FREE_PAGES),
> > > -		free_pcp,
> > > -		global_page_state(NR_FREE_CMA_PAGES));
> > > +	printk("active_anon:%lu inactive_anon:%lu isolated_anon:%lu\n",
> > > +	       global_node_page_state(NR_ACTIVE_ANON),
> > > +	       global_node_page_state(NR_INACTIVE_ANON),
> > > +	       global_node_page_state(NR_ISOLATED_ANON));
> > > +	printk("active_file:%lu inactive_file:%lu isolated_file:%lu\n",
> > > +	       global_node_page_state(NR_ACTIVE_FILE),
> > > +	       global_node_page_state(NR_INACTIVE_FILE),
> > > +	       global_node_page_state(NR_ISOLATED_FILE));
> > > +	printk("unevictable:%lu dirty:%lu writeback:%lu unstable:%lu\n",
> > > +	       global_node_page_state(NR_UNEVICTABLE),
> > > +	       global_node_page_state(NR_FILE_DIRTY),
> > > +	       global_node_page_state(NR_WRITEBACK),
> > > +	       global_node_page_state(NR_UNSTABLE_NFS));
> > > +	printk("slab_reclaimable:%lu slab_unreclaimable:%lu\n",
> > > +	       global_page_state(NR_SLAB_RECLAIMABLE),
> > > +	       global_page_state(NR_SLAB_UNRECLAIMABLE));
> > > +	printk("mapped:%lu shmem:%lu pagetables:%lu bounce:%lu\n",
> > > +	       global_node_page_state(NR_FILE_MAPPED),
> > > +	       global_node_page_state(NR_SHMEM),
> > > +	       global_page_state(NR_PAGETABLE),
> > > +	       global_page_state(NR_BOUNCE));
> > > +	printk("free:%lu free_pcp:%lu free_cma:%lu\n",
> > > +	       global_page_state(NR_FREE_PAGES),
> > > +	       free_pcp,
> > > +	       global_page_state(NR_FREE_CMA_PAGES));
> > 
> > a side note:
> > 
> > this can make it harder to read, in _the worst case_. one printk()
> > guaranteed that we would see a single line in the serial log/etc.
> > the sort of a problem with multiple printks is that printks coming
> > from other CPUs will split that "previously single" line.
> 
> Not true.  Note the multiple \n uses in the original code.

one printk call ends up in logbuf as a single entry and, thus, we print
it to the serial console in one shot (what is the correct english word
to use here?). multiple printks result in multiple logbuf entries, and
printks from other CPUs can mix in.

so the difference is:


	CPU0						CPU1
							printk(foo\n)
printk(..isolated_anon\n...isolated_file\n...)
							printk(bar\n)

vs

	CPU0						CPU1
printk(..isolated_anon\n)
							printk(foo\n)
printk(...isolated_file\n)
							printk(bar\n)
printk(...\n)

not the same thing.

and the slower the serial console is the more messages potentially
can appear between "..isolated_anon\n" and "...isolated_file\n".

	-ss