Re: vprintf performance

[Pádraig Brady]

On 03/02/11 11:18, Bruno Haible wrote:
> Hello Pádraig,
> 
>> The reason is because xprintf pulls in the whole gnulib vasnprintf
>> implementation, and then it does a huge number of reallocs.
> 
> Did a profiling reveal where in vasnprintf the speed problems are?

All I did was narrow it down to reallocs.
I'll have another look after work.

$ dd count=1 if=/dev/zero | ltrace -c od-printf -Ax -tx1z -v >/dev/null
1+0 records in
1+0 records out
512 bytes (512 B) copied, 2.9682e-05 s, 17.2 MB/s
% time     seconds  usecs/call     calls      function
------ ----------- ----------- --------- --------------------
 75.26    0.021788          40       544 __printf_chk
  4.87    0.001409          42        33 fread_unlocked
  4.75    0.001374          41        33 fputs_unlocked
  4.29    0.001241          38        32 __ctype_b_loc
  4.29    0.001241          38        32 fwrite_unlocked
  1.86    0.000539         539         1 dcgettext
  1.45    0.000419         419         1 setlocale
  0.94    0.000272          90         3 fclose
  0.60    0.000175          43         4 getopt_long
  0.28    0.000080          40         2 __fpending
  0.21    0.000061          61         1 __sprintf_chk
  0.17    0.000050          50         1 bindtextdomain
  0.16    0.000047          47         1 realloc
  0.15    0.000044          44         1 strrchr
  0.15    0.000044          44         1 textdomain
  0.15    0.000044          44         1 __cxa_atexit
  0.15    0.000043          43         1 malloc
  0.14    0.000040          40         1 free
  0.13    0.000039          39         1 __errno_location
------ ----------- ----------- --------- --------------------
100.00    0.028950                   694 total

$ dd count=1 if=/dev/zero | ltrace -c od-xprintf -Ax -tx1z -v >/dev/null
1+0 records in
1+0 records out
512 bytes (512 B) copied, 6.7049e-05 s, 7.6 MB/s
% time     seconds  usecs/call     calls      function
------ ----------- ----------- --------- --------------------
 18.23    0.041042          40      1025 malloc
 17.79    0.040051          39      1025 realloc
 17.42    0.039232          38      1025 free
 17.04    0.038359          37      1024 memcpy
  8.90    0.020039          39       512 __snprintf_chk
  8.53    0.019214          37       513 __errno_location
  8.50    0.019138          37       512 fwrite
  0.60    0.001353          41        33 fputs_unlocked
  0.60    0.001350          40        33 fread_unlocked
  0.55    0.001236          38        32 __printf_chk
  0.54    0.001223          38        32 __ctype_b_loc
  0.54    0.001211          37        32 fwrite_unlocked
  0.23    0.000527         527         1 dcgettext
  0.18    0.000413         413         1 setlocale
  0.12    0.000275          91         3 fclose
  0.08    0.000171          42         4 getopt_long
  0.04    0.000080          40         2 __fpending
  0.03    0.000061          61         1 __sprintf_chk
  0.02    0.000047          47         1 bindtextdomain
  0.02    0.000043          43         1 strrchr
  0.02    0.000043          43         1 textdomain
  0.02    0.000043          43         1 __cxa_atexit
------ ----------- ----------- --------- --------------------
100.00    0.225151                  5814 total

cheers,
Pádraig.