15002 – [3.4 only] Linewise stream input is unusably slow (std::string slow) (original) (raw)

| 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 [1] 19.5 10.20 0.00 std:🧵:replace(__gnu_cxx::__normal_iterator<char*, std::string>, __gnu_cxx::__normal_iterator<char*, std::string>, unsigned int, char) [1] ----------------------------------------------- [2] 17.6 9.17 0.00 memset [2] ----------------------------------------------- [3] 14.5 7.56 0.00 std:🧵:_M_mutate(unsigned int, unsigned int, unsigned int) [3] ----------------------------------------------- [4] 12.0 6.29 0.00 std:🧵:append(unsigned int, char) [4] ----------------------------------------------- [5] 10.7 5.59 0.00 std::basic_istream<char, std::char_traits >& std::getline<char, std::char_traits, std::allocator >(std::basic_istream<char, std::char_traits >&, std::basic_string<char, std::char_traits, std::allocator >&, char) [5] ----------------------------------------------- [6] 10.4 5.41 0.00 std:🧵:_M_iend() const [6] ----------------------------------------------- [7] 8.5 4.42 0.00 std::basic_streambuf<char, std::char_traits >::sbumpc() [7] ----------------------------------------------- [8] 4.6 2.40 0.00 std:🧵:_M_ibegin() const [8] ----------------------------------------------- [9] 1.5 0.79 0.00 read [9] Much time seems to be lost in std:🧵: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. Comment 1 aaron 2004-04-18 14:08:13 UTC Created attachment 6111 [details] The test case Unpack it and run 'make test'. Notice that it'll create a temporary file of about 40MB! Comment 2 aaron 2004-04-18 14:09:15 UTC Created attachment 6112 [details] The gprof output for the streams program The complete output of 'gprof -q' on the 'streams' test program. Comment 3 Drea Pinski 2004-04-18 14:20:11 UTC Confirmed, the issue might be using wrong std::string functions to do std::getline. Otherwise std:: string is where it is slow. Comment 4 aaron 2004-04-18 14:39:04 UTC That's not true. std::getline() is HORRIBLY slow (more than 30 times slower than fgets()), basically making it unusable to read large files. std::ifstream::getline() is still VERY slow (more than 4 times slower than fgets()), which still makes it nearly unusable. This might not be a 'critical' bug, but it has at least severity 'normal' because almost every serious C++ program uses linewise input somewhere. Anyway, I leave it to you to change that if you feel like :-) Comment 5 Drea Pinski 2004-04-18 14:46:59 UTC Well for the mainline it is already faster: tin:~/src/gnu/gcctest/iotest/iotest>time ./streams 3.510u 0.040s 0:03.69 96.2% 0+0k 0+0io 202pf+0w tin:~/src/gnu/gcctest/iotest/iotest>time ./streams2 0.420u 0.040s 0:00.69 66.6% 0+0k 0+0io 200pf+0w tin:~/src/gnu/gcctest/iotest/iotest>time ./stdio 0.090u 0.060s 0:00.14 107.1% 0+0k 0+0io 80pf+0w But since this has never been fast, it is an enhancement. Comment 7 Drea Pinski 2004-04-20 16:44:06 UTC Paolo, your patch helped a lot (I looked a profile generated by Shark). I noticed that most of the time now is spent in std:🧵:_M_mutate from std:🧵:_M_replace_aux, not doing much at all. Some suggestions after looking into the source/asm: The calculation for __src could be moved inside the if statements, removing a load and two adds. On the same box as before after Paolo's patch, so a little more than a 2x speedup: tin:~/src/gnu/gcctest/iotest/iotest>time ./streams 1.340u 0.100s 0:01.43 100.6% 0+0k 0+0io 202pf+0w tin:~/src/gnu/gcctest/iotest/iotest>time ./streams2 0.430u 0.010s 0:00.44 100.0% 0+0k 0+0io 199pf+0w tin:~/src/gnu/gcctest/iotest/iotest>time ./stdio 0.080u 0.060s 0:00.15 93.3% 0+0k 0+0io 80pf+0w Comment 8 Paolo Carlini 2004-04-20 16:59:08 UTC Thanks Andrew for testing again and in particular for your suggestion! Comment 13 Drea Pinski 2004-04-26 15:42:53 UTC This is now fixed on the mainline: tin:~/src/gnu/gcctest/iotest/iotest>time ./streams2 0.100u 0.040s 0:00.14 100.0% 0+0k 0+0io 205pf+0w tin:~/src/gnu/gcctest/iotest/iotest>time ./stdio 0.080u 0.050s 0:00.14 92.8% 0+0k 0+0io 85pf+0w tin:~/src/gnu/gcctest/iotest/iotest>time ./streams 0.420u 0.070s 0:00.49 100.0% 0+0k 0+0io 208pf+0w Which makes using streams to very close to running stdio. Paolo says he is going to try to get this into 3.4.1 also. Comment 15 GCC Commits 2004-05-09 23:28:02 UTC Subject: Bug 15002 CVSROOT: /cvs/gcc Module name: gcc Branch: gcc-3_4-branch Changes by: paolo@gcc.gnu.org 2004-05-09 23:27:57 Modified files: libstdc++-v3 : ChangeLog libstdc++-v3/include/bits: basic_string.tcc istream.tcc Added files: libstdc++-v3/testsuite/27_io/basic_istream/getline/char: 4.cc 5.cc libstdc++-v3/testsuite/21_strings/basic_string/inserters_extractors/char: 10.cc libstdc++-v3/testsuite/21_strings/basic_string/inserters_extractors/wchar_t: 10.cc Log message: 2004-05-09 Paolo Carlini <pcarlini@suse.de> * testsuite/21_strings/basic_string/inserters_extractors/char/10.cc: New. * testsuite/21_strings/basic_string/inserters_extractors/wchar_t/10.cc: Likewise. * testsuite/27_io/basic_istream/getline/char/5.cc: Likewise. 2004-05-09 Paolo Carlini <pcarlini@suse.de> PR libstdc++/15002 (continued again) * include/bits/istream.tcc (getline(basic_istream<>&, basic_string<>&, _CharT)): Use a temporary buffer, thus avoiding reallocation for common case. * include/bits/basic_string.tcc (_S_construct(_InIterator, _InIterator, const _Alloc&, input_iterator_tag)): Tweak size of temporary buffer to a power of two. * testsuite/27_io/basic_istream/getline/char/4.cc: Add comment. 2004-05-09 Paolo Carlini <pcarlini@suse.de> Petur Runolfsson <peturr02@ru.is> PR libstdc++/15002 (continued) * include/bits/istream.tcc (basic_istream<>::getline(char_type*, streamsize, char_type)): Use traits::find/copy in a loop to speed up greatly the function in the common case (I/O buffer size >> 1). 2004-05-09 Paolo Carlini <pcarlini@suse.de> * testsuite/27_io/basic_istream/getline/char/4.cc: New. * include/bits/istream.tcc (getline(basic_istream<>&, basic_string<>&, _CharT)): Change to use sgetc()/snextc() instead of sbumpc(), consistently with the other functions, thus also dealing correctly with the case of exceeded string::max_size(). Patches: http://gcc.gnu.org/cgi-bin/cvsweb.cgi/gcc/libstdc++-v3/ChangeLog.diff?cvsroot=gcc&only_with_tag=gcc-3_4-branch&r1=1.2224.2.96&r2=1.2224.2.97 http://gcc.gnu.org/cgi-bin/cvsweb.cgi/gcc/libstdc++-v3/include/bits/basic_string.tcc.diff?cvsroot=gcc&only_with_tag=gcc-3_4-branch&r1=1.46.4.6&r2=1.46.4.7 http://gcc.gnu.org/cgi-bin/cvsweb.cgi/gcc/libstdc++-v3/include/bits/istream.tcc.diff?cvsroot=gcc&only_with_tag=gcc-3_4-branch&r1=1.60.4.2&r2=1.60.4.3 http://gcc.gnu.org/cgi-bin/cvsweb.cgi/gcc/libstdc++-v3/testsuite/27_io/basic_istream/getline/char/4.cc.diff?cvsroot=gcc&only_with_tag=gcc-3_4-branch&r1=NONE&r2=1.2.4.1 http://gcc.gnu.org/cgi-bin/cvsweb.cgi/gcc/libstdc++-v3/testsuite/27_io/basic_istream/getline/char/5.cc.diff?cvsroot=gcc&only_with_tag=gcc-3_4-branch&r1=NONE&r2=1.1.4.1 http://gcc.gnu.org/cgi-bin/cvsweb.cgi/gcc/libstdc++-v3/testsuite/21_strings/basic_string/inserters_extractors/char/10.cc.diff?cvsroot=gcc&only_with_tag=gcc-3_4-branch&r1=NONE&r2=1.1.4.1 http://gcc.gnu.org/cgi-bin/cvsweb.cgi/gcc/libstdc++-v3/testsuite/21_strings/basic_string/inserters_extractors/wchar_t/10.cc.diff?cvsroot=gcc&only_with_tag=gcc-3_4-branch&r1=NONE&r2=1.1.4.1 Comment 16 Paolo Carlini 2004-05-09 23:33:29 UTC Fixed for 3.4.1. | | | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | |