[Octave-bug-tracker] [bug #40304] Excessive I/O in load function with g++/libstdc++ 4.4

[Mike Miller]

Update of bug #40304 (project octave):

                Severity:              3 - Normal => 2 - Minor              
                  Status:            Works For Me => Wont Fix               
                 Summary: Excessive I/O in load function => Excessive I/O in
load function with g++/libstdc++ 4.4

    _______________________________________________________

Follow-up Comment #21:

Ok, I can now reproduce this behavior but I believe the problem is entirely
due to a gcc bug or feature that has subsequently been fixed or improved. You
said this behavior shows up on Scientific Linux 6.4, which uses gcc 4.4.7. I
can get the same behavior to show on my Debian system by compiling with gcc
4.4.7 and running with the 4.4.7 libstdc++ shared library.

With gcc/g++/libstdc++ 4.4.7:


00:51:13.464509 open("Extended_Molecule", O_RDONLY) = 3
00:51:13.464532 fstat(3, {st_mode=S_IFREG|0640, st_size=3041030, ...}) = 0
00:51:13.464563 lseek(3, 0, SEEK_SET)   = 0
00:51:13.464579 read(3, " # name:", 8)  = 8
00:51:13.464597 lseek(3, 512, SEEK_SET) = 512
00:51:13.464612 read(3, "0\t1\n\t34\t", 8) = 8
00:51:13.464628 lseek(3, 1024, SEEK_SET) = 1024
00:51:13.464643 read(3, "6\t0\t0\t1\n", 8) = 8
00:51:13.464659 lseek(3, 2048, SEEK_SET) = 2048
00:51:13.464674 read(3, "\n\t157\t6\t", 8) = 8
00:51:13.464690 lseek(3, 4096, SEEK_SET) = 4096
00:51:13.464705 read(3, "\t0\t0\t1\n\t", 8) = 8
00:51:13.464721 lseek(3, 8192, SEEK_SET) = 8192
00:51:13.464736 read(3, "0\t0\t1\n\t6", 8) = 8
00:51:13.464752 lseek(3, 16384, SEEK_SET) = 16384
00:51:13.464767 read(3, "241\t6\t0\t", 8) = 8
00:51:13.464783 lseek(3, 32768, SEEK_SET) = 32768
00:51:13.464798 read(3, "6\t0\t0\t1\n", 8) = 8
00:51:13.464814 lseek(3, 65536, SEEK_SET) = 65536
00:51:13.464829 read(3, "\t4752\t6\t", 8) = 8
00:51:13.464846 lseek(3, 131072, SEEK_SET) = 131072
00:51:13.464861 read(3, "433\t6\t0\t", 8) = 8
00:51:13.464877 lseek(3, 262144, SEEK_SET) = 262144
00:51:13.464892 read(3, "9\t\t2099\t", 8) = 8
00:51:13.464908 lseek(3, 524288, SEEK_SET) = 524288
00:51:13.464923 read(3, "6823\t\t68", 8) = 8
00:51:13.464939 lseek(3, 1048576, SEEK_SET) = 1048576
00:51:13.464954 read(3, "00000\n\t1", 8) = 8
00:51:13.464970 lseek(3, 2097152, SEEK_SET) = 2097152
00:51:13.464985 read(3, "0000\n\t1\t", 8) = 8
00:51:13.465007 close(3)                = 0
00:51:13.465030 open("Extended_Molecule", O_RDONLY) = 3
00:51:13.465059 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:51:13.465081 close(3)                = 0
00:51:13.465103 open("Extended_Molecule", O_RDONLY) = 3
00:51:13.465125 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:51:13.465147 lseek(3, 0, SEEK_SET)   = 0
00:51:13.465164 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:51:13.465185 lseek(3, 0, SEEK_SET)   = 0
00:51:13.465201 lseek(3, 116, SEEK_SET) = 116
00:51:13.465217 read(3, "# columns: 5\n\t1\t6\t0\t0\t1\n\t2\t6\t0\t0"...,
8191) = 8191
00:51:13.465234 lseek(3, 124, SEEK_SET) = 124
00:51:13.465250 read(3, "s: 5\n\t1\t6\t0\t0\t1\n\t2\t6\t0\t0\t1\n\t3\t6\t"...,
8191) = 8191
00:51:13.465272 lseek(3, 0, SEEK_SET)   = 0
00:51:13.465291 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:51:13.465322 close(3)                = 0
00:51:13.465344 open("Extended_Molecule", O_RDONLY) = 3
00:51:13.465368 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:51:13.465401 lseek(3, -8160, SEEK_CUR) = 31
00:51:13.465419 read(3, "\t1\n # name: FermiE\n # type: scal"..., 8191) =
8191
00:51:13.465460 lseek(3, -8156, SEEK_CUR) = 66
00:51:13.465476 read(3, "\t0\n # name: iorb\n # type: matrix"..., 8191) =
8191
00:51:13.465520 mmap(NULL, 425984, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9dd3b4a000
00:51:13.465544 lseek(3, -8128, SEEK_CUR) = 129
00:51:13.465560 read(3,
"\t1\t6\t0\t0\t1\n\t2\t6\t0\t0\t1\n\t3\t6\t0\t0\t1"..., 8191) = 8191
00:51:13.465581 lseek(3, -8189, SEEK_CUR) = 131
00:51:13.465596 read(3,
"\t6\t0\t0\t1\n\t2\t6\t0\t0\t1\n\t3\t6\t0\t0\t1\n\t"..., 8191) = 8191
00:51:13.465616 lseek(3, -8189, SEEK_CUR) = 133
00:51:13.465631 read(3,
"\t0\t0\t1\n\t2\t6\t0\t0\t1\n\t3\t6\t0\t0\t1\n\t4\t"..., 8191) = 8191
00:51:13.465653 lseek(3, -8189, SEEK_CUR) = 135
00:51:13.465668 read(3,
"\t0\t1\n\t2\t6\t0\t0\t1\n\t3\t6\t0\t0\t1\n\t4\t6\t"..., 8191) = 8191
00:51:13.465688 lseek(3, -8189, SEEK_CUR) = 137


With gcc/g++/libstdc++ 4.8.2:


00:50:52.688530 open("Extended_Molecule", O_RDONLY) = 3
00:50:52.688554 fstat(3, {st_mode=S_IFREG|0640, st_size=3041030, ...}) = 0
00:50:52.688584 lseek(3, 0, SEEK_SET)   = 0
00:50:52.688601 read(3, " # name:", 8)  = 8
00:50:52.688618 lseek(3, 512, SEEK_SET) = 512
00:50:52.688633 read(3, "0\t1\n\t34\t", 8) = 8
00:50:52.688649 lseek(3, 1024, SEEK_SET) = 1024
00:50:52.688664 read(3, "6\t0\t0\t1\n", 8) = 8
00:50:52.688680 lseek(3, 2048, SEEK_SET) = 2048
00:50:52.688695 read(3, "\n\t157\t6\t", 8) = 8
00:50:52.688711 lseek(3, 4096, SEEK_SET) = 4096
00:50:52.688726 read(3, "\t0\t0\t1\n\t", 8) = 8
00:50:52.688741 lseek(3, 8192, SEEK_SET) = 8192
00:50:52.688756 read(3, "0\t0\t1\n\t6", 8) = 8
00:50:52.688772 lseek(3, 16384, SEEK_SET) = 16384
00:50:52.688787 read(3, "241\t6\t0\t", 8) = 8
00:50:52.688803 lseek(3, 32768, SEEK_SET) = 32768
00:50:52.688818 read(3, "6\t0\t0\t1\n", 8) = 8
00:50:52.688833 lseek(3, 65536, SEEK_SET) = 65536
00:50:52.688848 read(3, "\t4752\t6\t", 8) = 8
00:50:52.688864 lseek(3, 131072, SEEK_SET) = 131072
00:50:52.688879 read(3, "433\t6\t0\t", 8) = 8
00:50:52.688895 lseek(3, 262144, SEEK_SET) = 262144
00:50:52.688910 read(3, "9\t\t2099\t", 8) = 8
00:50:52.688926 lseek(3, 524288, SEEK_SET) = 524288
00:50:52.688940 read(3, "6823\t\t68", 8) = 8
00:50:52.688956 lseek(3, 1048576, SEEK_SET) = 1048576
00:50:52.688971 read(3, "00000\n\t1", 8) = 8
00:50:52.688987 lseek(3, 2097152, SEEK_SET) = 2097152
00:50:52.689002 read(3, "0000\n\t1\t", 8) = 8
00:50:52.689023 close(3)                = 0
00:50:52.689046 open("Extended_Molecule", O_RDONLY) = 3
00:50:52.689074 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:50:52.689096 close(3)                = 0
00:50:52.689119 open("Extended_Molecule", O_RDONLY) = 3
00:50:52.689140 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:50:52.689162 lseek(3, 0, SEEK_SET)   = 0
00:50:52.689182 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:50:52.689204 lseek(3, 0, SEEK_SET)   = 0
00:50:52.689221 lseek(3, 116, SEEK_SET) = 116
00:50:52.689236 read(3, "# columns: 5\n\t1\t6\t0\t0\t1\n\t2\t6\t0\t0"...,
8191) = 8191
00:50:52.689254 lseek(3, 124, SEEK_SET) = 124
00:50:52.689269 read(3, "s: 5\n\t1\t6\t0\t0\t1\n\t2\t6\t0\t0\t1\n\t3\t6\t"...,
8191) = 8191
00:50:52.689288 lseek(3, 0, SEEK_SET)   = 0
00:50:52.689305 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:50:52.689334 close(3)                = 0
00:50:52.689353 open("Extended_Molecule", O_RDONLY) = 3
00:50:52.689378 read(3, " # name: nspin\n # type: scalar\n\t"..., 8191) =
8191
00:50:52.689410 lseek(3, 0, SEEK_CUR)   = 8191
00:50:52.689452 lseek(3, 0, SEEK_CUR)   = 8191
00:50:52.689491 mmap(NULL, 425984, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f01d9131000
00:50:52.689515 lseek(3, 0, SEEK_CUR)   = 8191
00:50:52.689533 lseek(3, 0, SEEK_CUR)   = 8191
00:50:52.689550 lseek(3, 0, SEEK_CUR)   = 8191
00:50:52.689568 lseek(3, 0, SEEK_CUR)   = 8191
00:50:52.689585 lseek(3, 0, SEEK_CUR)   = 8191


I can't say for certain that Octave is doing nothing wrong, but it seems that
whatever was causing the excessive seeks and reads in the 4.4.7 version of gcc
has been fixed or mitigated in a newer version of gcc. I'm marking this as
"won't fix" but leaving open for now, if you'd like to investigate further or
suggest a change that might help the performance with your compiler.

    _______________________________________________________

Reply to this item at:

  <http://savannah.gnu.org/bugs/?40304>

_______________________________________________
  Message sent via/by Savannah
  http://savannah.gnu.org/