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

[Isaac Dunham]

On Mon, Nov 24, 2014 at 05:26:06PM -0800, enh wrote:
> * the kernel buffer hasn't defaulted to 16KiB for a very long time.
> i'm not sure why the original code said < 2 rather than <= 0 (or 1KiB,
> say), but i've left that as it was.
> 
> * 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.)
> 
> * 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.
> 
> here's the patch, which attempts to imitate your style:
> 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.
> +    if (size < 0) size = 16384;
>      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;
I presume the theory here is that log levels might eventually end up going
above 8, despite the documentation implying otherwise?
And of course everything assumes that < and > are off-limits for the contents.

> +      } else {
> +        end = strchr(data+i, '\n');
> +        if (end) {
> +          xwrite(1, data+i, end-(data+i)+1);
> +          i += end - (data+i) + 1;

Somehow this whole bit reminds me of something I wrote not long ago,
where I took care of unwanted strings by moving the memory contents 
towards the start.
Applied here, it might look like this:

void memback(long delbytes, char *string)
{
  // could be adjusted to not need strlen() in our case...
  memmove(string, string + delbytes, strlen(string) + delbytes);
}

...
  while ((cur = strchr(cur, '<') != 0) {
    memback(3, cur);
  }
 

This will call memmove() a lot; on the other hand, it can call write once.

> +        } else {
> +          xwrite(1, data+i, size-i);
> +          xputc('\n');
> +          i = size;

I'm guessing you want "xwriteall()" instead of "xwrite()"; 
xwriteall retries until everything has been written.
> +        }
> +      }
>      }
> -    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 :-) )

Adding an option is simple:

-USE_DMESG(NEWTOY(dmesg, "s#n#c", TOYFLAG_BIN)
+USE_DMESG(NEWTOY(dmesg, "s#n#cr", TOYFLAG_BIN)
...
     -n  Set kernel logging level (1-9).
+    -r  Print the raw message buffer.
     -s  Size of buffer to read (in bytes), default 16384.
...
+  if (toys.optflags&FLAG_r) {
+    //write the buffer in its entirety
+  }

(I suppose that this could be done with a single call to xwriteall)
www/code.html has more on how to write things for toybox.


And I notice now that dmesg doesn't use the FLAG_* macros, but
instead hardcodes options by their offset in the optsring.
It was last touched about 2 years ago just after the FLAG_* macros,
so that isn't surprising.

 1416885052.0