[Toybox] [PATCH] fix dmesg default size/level filtering/performance

[Rob Landley]

On 11/24/14 19:26, enh wrote:
> * the kernel buffer hasn't defaulted to 16KiB for a very long time.

This command was written in 2007. :)

> i'm not sure why the original code said < 2 rather than <= 0 (or 1KiB,
> say), but i've left that as it was.

At a wild guess because a size of one should almost always only show a
newline, but it's been a while.

> * there's also a bug with the filtering out of level markers; they can
> be more than one digit. (this is true of all kernels, not just Android
> ones.)

Somebody should poke Michael Kerrisk to update the klogctl man page
then, it says it goes from 1-7. (Just before RETURN VALUE.)

Ah, I see somebody already has:

http://man7.org/linux/man-pages/man3/klogctl.3.html

Ubuntu 12.04's man pages haven't gotten the message yet...

> * finally, the use of xputc for every character makes the toybox dmesg
> human-noticeably slow. writing line at a time is orders of magnitude
> faster/fewer syscalls.

Indeed. My bad.

(When I first started this project I was doing the simplest and smallest
implementations I could, putting "feature complete" third and
performance fourth. I've since reorganized that to put "feature
complete" in the second spot with fast and small tied for third. Simple
is still #1, but deciding what "simple" is can be complicated. :)

> here's the patch, which attempts to imitate your style:
> 
> diff --git a/generated/help.h b/generated/help.h
> index 6c017cf..1a44a37 100644
> --- a/generated/help.h
> +++ b/generated/help.h
> @@ -54,7 +54,7 @@
> 
>  #define help_hostname "usage: hostname [newname]\n\nGet/Set the
> current hostname\n\n"
> 
> -#define help_dmesg "usage: dmesg [-n level] [-s bufsize] |
> -c\n\nPrint or control the kernel ring buffer.\n\n-n Set kernel
> logging level (1-9).\n-s Size of buffer to read (in bytes), default
> 16384.\n-c Clear the ring buffer after printing.\n\n"
> +#define help_dmesg "usage: dmesg [-n level] [-s bufsize] |
> -c\n\nPrint or control the kernel ring buffer.\n\n-n Set kernel
> logging level (1-9).\n-s Size of buffer to read (in bytes), default
> kernel buffer size.\n-c Clear the ring buffer after printing.\n\n"
> 
>  #define help_yes "usage: yes [args...]\n\nRepeatedly output line
> until killed. If no args, output 'y'.\n\n\n"

This is a patch to a generated file. Your android build needs it because
you snapshot generated files, but we recreate help.h from the formatted
comments at the top of each C file every build.

If you're curious (I.E. "digression, feel free to ignore"), the
mechanism is that scripts/make.sh compiles and runs
scripts/config2help.c and feeds it the output of a sed invocation
against toys/*/*.c (filtering for the filenames that case insensitive
match an enabled config symbol).

The current version of config2help.c was written back in january:

http://landley.net/notes-2014.html#12-01-2014
http://lists.landley.net/pipermail/toybox-landley.net/2014-January/001523.html
http://lists.landley.net/pipermail/toybox-landley.net/2014-January/001562.html

Before that it was config2help.pl which isn't a build dependency we
wanted (for reasons explained in that youtube video).

Returning to the "defining simple isn't simple" problem: At the design
level, there's a certain amount of tension between "simple" as in
uncomplicated and "simple" as in automated.

For example, adding a new command to toybox means adding a single
self-contained file to one of the directories under toys/ and that's it,
you shouldn't have to touch anything else.

http://landley.net/toybox/code.html#adding

(Even adding a directory under toys means "mkdir -p toys/rutabega;
echo 'name for menu is first line of README' > toys/rutabega/README".
It's really a flat namespace, the directories were because annotating
"this is a posix command" and "this is an LSB command" in menuconfig got
awkward.)

But the amount of work that goes on behind the scenes to make that
_work_, to generate the help text, the gcc invocations, the kconfig
files, FLAG_x macros for option parsing, and so on _from_ that... Well
it's the difference between stick shift and automatic transmission. Do
you want simple to drive vs simple to take apart and put back together?
(I try not to go too far in either direction...)

> diff --git a/toys/lsb/dmesg.c b/toys/lsb/dmesg.c
> index 1003256..d4a2b66 100644
> --- a/toys/lsb/dmesg.c
> +++ b/toys/lsb/dmesg.c
> @@ -15,7 +15,7 @@ config DMESG
>      Print or control the kernel ring buffer.
> 
>      -n Set kernel logging level (1-9).
> -    -s Size of buffer to read (in bytes), default 16384.
> +    -s Size of buffer to read (in bytes), default kernel buffer size.
>      -c Clear the ring buffer after printing.
>  */
> 
> @@ -34,22 +34,34 @@ void dmesg_main(void)
>    if (toys.optflags & 2) {
>      if (klogctl(8, NULL, TT.level)) error_exit("klogctl");
>    } else {
> -    int size, i, last = '\n';
> -    char *data;
> +    int size, i;
> +    char *data, *end;
> 
>      // Figure out how much data we need, and fetch it.
>      size = TT.size;
> -    if (size<2) size = 16384;
> +    if (size < 2) size = klogctl(10, 0, 0); // SYSLOG_ACTION_SIZE_BUFFER.

The kernel's minimum value is 12 bits (4k, LOG_BUF_SHIFT in
init/Kconfig), but we may actually want to _display_ less than that. The
klogctl() call returns the last X bytes in the buffer, and sometimes you
want to tail the sucker. :)

Sigh. This code is so old it predates the FLAG_x macro generation and is
using the raw flag numbers. Ooops, thought I'd cleaned all those out. :)

The argument parsing logic also grew the ability to enforce minimum,
maximum, and default values on numerical options, so I could say
"s#=16384" in the option string. But probing is a better solution.

> +    if (size < 0) size = 16384;

Hmmm, klogctl type 10 added in the 2.6.6 kernel... I think I'm ok with
forcing earlier kernels to specify -s for now, and waiting for somebody
to complain. (I want to perror_exit() when it gives an error, because it
shouldn't do that...)

>      data = xmalloc(size);
>      size = klogctl(3 + (toys.optflags&1), data, size);
>      if (size < 0) error_exit("klogctl");
> 
> -    // Display data, filtering out level markers.
> +    // Display data, filtering out level markers (<\d+>).
>      for (i=0; i<size; ) {
> -      if (last=='\n' && data[i]=='<') i += 3;
> -      else xputc(last = data[i++]);
> +      if (data[i]=='<') {
> +        end = strchr(data+i, '>');
> +        if (end) i = end-data+1;
> +      } else {
> +        end = strchr(data+i, '\n');
> +        if (end) {
> +          xwrite(1, data+i, end-(data+i)+1);
> +          i += end - (data+i) + 1;
> +        } else {
> +          xwrite(1, data+i, size-i);
> +          xputc('\n');
> +          i = size;
> +        }
> +      }
>      }
> -    if (last!='\n') xputc('\n');
>      if (CFG_TOYBOX_FREE) free(data);
>    }
>  }
> 
> i'm assuming no one actually cares about the old Android "implicit -r"
> behavior.
>
> if i get a complaint, adding -r is trivial. (once i learn
> how to add an option at all :-) )

I just added -r, since there was interest and it's easy _not_ to do
something. :)

To add a command line option: the second argument of the NEWTOY() macro
is the optflags format string, which is a distant descendant of the
optarg(3) format. It's called automatically by the startup code in
main() before caling the relevant command_main():

  main()->toybox_main()->toy_init()->toy_singleinit()->get_optflags()

(Or for scripts/single.sh builds:
main()->toy_singleinit()->get_optflags() .)

The giant comment at the start of lib/args.c explains the syntax, and
there's a somewhat more verbose introduction at:

http://landley.net/toybox/code.html#lib_args

The FLAG_x macros are generated automatically, you mask them against
toys.optargs to see if the relevant bit is set. (Each option letter gets
a bit, in the same order as binary digits. So for "abcd", d=1, c=2, b=4,
a=8. Sometimes we use the value of a flag to simpify the code, but I try
to comment that when it happens.)

Rob

 1416973337.0