[Bug libstdc++/15002] New: Linewise stream input is unusably slow

["aaron at isotton dot com" <gcc-bugzilla at gcc dot gnu dot org>]

I noticed that std::getline is unusably slow. So I wrote three test programs, 
one using fgets(), one using std::getline() and one using 
std::ifstream::getline(). I have read the same file (200000 lines, 39MB) 
in all cases; here are the results:

Using fgets():

aisotton@zarathustra:~/test/iotest$ time ./stdio

real    0m0.222s
user    0m0.109s
sys     0m0.073s

------------

Using std::getline():

aisotton@zarathustra:~/test/iotest$ time ./streams

real    0m6.945s
user    0m5.316s
sys     0m0.074s

------------

Using std::ifstream::getline():

aisotton@zarathustra:~/test/iotest$ time ./streams2

real    0m1.002s
user    0m0.890s
sys     0m0.074s

------------

fgets() is more than 30 times faster than std::getline(), and more than 4 times
faster than std::ifstream::getline(). This is not acceptable.

- It is not a buffering problem; using strace I found out that fgets() uses a
4096 byte buffer, and the C++ streams a 8192 byte buffer.

- It has nothing to do with optimization. The values are roughly the same for
all optimization levels.

- g++ 2.95 performs better than 3.2, and 3.2 better than 3.3, but they are still
slow. Here the exact versions:

aisotton@zarathustra:~/test/iotest$ g++-2.95 -v
Reading specs from /usr/lib/gcc-lib/i386-linux/2.95.4/specs
gcc version 2.95.4 20011002 (Debian prerelease)

aisotton@zarathustra:~/test/iotest$ g++-3.2 -v
Reading specs from /usr/lib/gcc-lib/i386-linux/3.2.3/specs
Configured with: ../src/configure -v 
--enable-languages=c,c++,f77,objc,ada --prefix=/usr 
--mandir=/usr/share/man --infodir=/usr/share/info 
--with-gxx-include-dir=/usr/include/c++/3.2 --enable-shared 
--with-system-zlib --enable-nls --without-included-gettext 
--enable-__cxa_atexit --enable-clocale=gnu --enable-objc-gc i386-linux
Thread model: posix
gcc version 3.2.3 (Debian)

aisotton@zarathustra:~/test/iotest$ g++-3.3 -v
Reading specs from /usr/lib/gcc-lib/i486-linux/3.3.3/specs
Configured with: ../src/configure -v 
--enable-languages=c,c++,java,f77,pascal,objc,ada,treelang --prefix=/usr 
--mandir=/usr/share/man --infodir=/usr/share/info 
--with-gxx-include-dir=/usr/include/c++/3.3 --enable-shared 
--with-system-zlib --enable-nls --without-included-gettext 
--enable-__cxa_atexit --enable-clocale=gnu --enable-debug 
--enable-java-gc=boehm --enable-java-awt=xlib --enable-objc-gc i486-linux
Thread model: posix
gcc version 3.3.3 (Debian 20040401)

And here the times for the second test:
-- 2.95 --
real    0m4.345s
user    0m4.058s
sys     0m0.067s

-- 3.2 --
real    0m5.728s
user    0m5.311s
sys     0m0.082s

-- 3.3 --
real    0m6.586s
user    0m5.298s
sys     0m0.091s

- It has nothing to do with stdio synchronisation, since we're reading from
files. To be really sure, I tried using

std::ios_base::sync_with_stdio(false);

(yes, before the first call!) but that didn't make any difference.

- Increasing the buffer size of the stream didn't make any real difference either.

Almost two years ago there was a long discussion about this on

http://groups.google.com/groups?hl=en&lr=&ie=UTF-8&oe=UTF-8&threadm=gidnla.uh5.ln%40ns1.irule.be&rnum=1&prev=/groups%3Fq%3Dg%252B%252B%2Bslow%2Bstd::getline%26hl%3Den%26lr%3D%26ie%3DUTF-8%26oe%3DUTF-8%26selm%3Dgidnla.uh5.ln%2540ns1.irule.be%26rnum%3D1

but they didn't really come to a solution.

I did some profiling; here the most interesting result (of the "streams" test):

		     Call graph (explanation follows)


granularity: each sample hit covers 4 byte(s) for 0.02% of 52.21 seconds

index % time    self  children    called     name
                                                 <spontaneous>
[1]     19.5   10.20    0.00                
std::string::replace(__gnu_cxx::__normal_iterator<char*, std::string>,
__gnu_cxx::__normal_iterator<char*, std::string>, unsigned int, char) [1]
-----------------------------------------------
                                                 <spontaneous>
[2]     17.6    9.17    0.00                 memset [2]
-----------------------------------------------
                                                 <spontaneous>
[3]     14.5    7.56    0.00                 std::string::_M_mutate(unsigned
int, unsigned int, unsigned int) [3]
-----------------------------------------------
                                                 <spontaneous>
[4]     12.0    6.29    0.00                 std::string::append(unsigned int,
char) [4]
-----------------------------------------------
                                                 <spontaneous>
[5]     10.7    5.59    0.00                 std::basic_istream<char,
std::char_traits<char> >& std::getline<char, std::char_traits<char>,
std::allocator<char> >(std::basic_istream<char, std::char_traits<char> >&,
std::basic_string<char, std::char_traits<char>, std::allocator<char> >&, char) [5]
-----------------------------------------------
                                                 <spontaneous>
[6]     10.4    5.41    0.00                 std::string::_M_iend() const [6]
-----------------------------------------------
                                                 <spontaneous>
[7]      8.5    4.42    0.00                 std::basic_streambuf<char,
std::char_traits<char> >::sbumpc() [7]
-----------------------------------------------
                                                 <spontaneous>
[8]      4.6    2.40    0.00                 std::string::_M_ibegin() const [8]
-----------------------------------------------
                                                 <spontaneous>
[9]      1.5    0.79    0.00                 read [9]

Much time seems to be lost in std::string::replace, for which I have no
explanatin whatsoever.

I've uploaded a very small "test suite" demonstrating the strange behaviour to
http://www.isotton.com/sandbox/iotest.tar.gz. Notice that it will create a file 
of about 40MB.

-- 
           Summary: Linewise stream input is unusably slow
           Product: gcc
           Version: 3.3.3
            Status: UNCONFIRMED
          Severity: critical
          Priority: P2
         Component: libstdc++
        AssignedTo: unassigned at gcc dot gnu dot org
        ReportedBy: aaron at isotton dot com
                CC: gcc-bugs at gcc dot gnu dot org
 GCC build triplet: i686-debian-linux
  GCC host triplet: i686-debian-linux
GCC target triplet: i686-debian-linux


http://gcc.gnu.org/bugzilla/show_bug.cgi?id=15002