Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 17 Sep 2010 15:09:01 -0700
From:      mdf@FreeBSD.org
To:        FreeBSD Arch <freebsd-arch@freebsd.org>
Cc:        Poul-Henning Kamp <phk@phk.freebsd.dk>
Subject:   Re: Towards a One True Printf
Message-ID:  <AANLkTinLSTtA4gSpAHvGqeyRPaBZMcTU5%2Bsjyn8RY5M0@mail.gmail.com>
In-Reply-To: <AANLkTi=uZqxw-VQ=K3AayWxewmZP8qCq1%2B-sdRs4m=Rc@mail.gmail.com>
References:  <AANLkTi=uZqxw-VQ=K3AayWxewmZP8qCq1%2B-sdRs4m=Rc@mail.gmail.com>

next in thread | previous in thread | raw e-mail | index | archive | help
On Fri, Sep 17, 2010 at 3:00 PM,  <mdf@freebsd.org> wrote:
> In an attempt to move towards a one true printf, I copied the base
> printf(3) implementation and changed the parameters to be similar to
> that of kvprintf(9), with a generic callback function on each print
> group. =A0The callback can easily be essentially the io_put() methods
> used for printf(3) but have the possibility of being something else
> too. =A0I used two different callback signatures -- the first is an
> optimized version that takes a char array (or presumably a wide char
> array to implement wprintf(3)), and the second is identical to the
> callback for kvprintf(9).
>
> http://people.freebsd.org/~mdf/vcb_printf.c
> http://people.freebsd.org/~mdf/vcb_printf2.c
>
> With changes in hand, I wrote a small user-space utility to benchmark
> the existing fprintf and sprintf versus the new one. =A0Note that the
> my_fprintf() function essentially borrows from the guts of
> printfcommon.h. =A0This
>
> http://people.freebsd.org/~mdf/printf_test.c
>
> The numbers I get I found rather interesting (also, I appear to be
> incompetent at calculating standard deviations; I'm sure someone will
> correct my code).
>
> # ./printf_test
> sprintf =A0 =A0: avg 0.090116202 sec, stdd 1.429e+10
> my_sprintf : avg 0.069918215 sec, stdd 1.167e+10
> my_sprintf2: avg 0.174028095 sec, stdd 1.167e+10
>
> fprintf =A0 =A0 /dev/null: avg 0.077871461 sec, stdd 1.65e+10
> my_fprintf =A0/dev/null: avg 0.102162816 sec, stdd 8.25e+09
> my_fprintf2 /dev/null: avg 0.307952770 sec, stdd 1.65e+10
>
> fprintf =A0 =A0 /tmp: avg 0.169936961 sec, stdd 1.167e+10
> my_fprintf =A0/tmp: avg 0.199943344 sec, stdd 1.167e+10
> my_fprintf2 /tmp: avg 0.399886075 sec, stdd 1.167e+10
> my_fwrite =A0 /tmp: avg 0.210000656 sec, stdd 1.167e+10
>
> I am unsurprised that the character-by-character callback is slower
> than bulk; in fact I didn't roll up the bulk callback until I saw how
> miserable the character-by-character callback was. =A0I put the code and
> numbers up for both because this also indicates the likelihood of a
> speedup in the kernel by doing a bulk callback for sprintf and sbuf
> operations.
>
> The new implementation is significantly faster when doing sprintf(3),
> significantly slower when printing to /dev/null, and slightly slower
> when printing to a file using an iovec, and slightly more slow using a
> naieve fwrite(3) callback. =A0In my case, /tmp is a UFS2 filesystem.
>
> My thought would be that, if we have a core implementation like
> cb_printf that can be used in both the kernel and libc/stdio, it would
> be fewer sources to maintain. =A0Also, the kernel cannot use the
> existing FILE based printf(3) but both sources can use a
> callback-based printf.
>
> I would like to discuss at some point after this adding a generic
> printf format specifier that basically takes a function pointer and
> argument and uses that to print. =A0Implementing that for both kernel
> and userspace would be easier with a single root printf
> implementation.
>
> So, thoughts? =A0Is the performance loss here acceptable, and is there
> something I missed in terms of making it run faster when printing to
> files?

Also, here is a diff from vfprintf.c to vcb_printf.c to show what
really changed:

http://people.freebsd.org/~mdf/vfprintf-to-vcb_printf.diff

Last, to make all this compile I had to add [v]cb_printf to libc's
Symbol.map and also I added __sfvwrite so my user-land performance
utility would build.

Thanks,
matthew



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?AANLkTinLSTtA4gSpAHvGqeyRPaBZMcTU5%2Bsjyn8RY5M0>