I'm having issues with gprof reporting empty times on the development version of my network program nettee. For a "normal" program (reads and writes files, no network) the results show reasonable times. In fact, for the last release of nettee (0.1.8) gprof worked too. However for the version I'm working on now gprof only shows 0.0 in the time fields.
Software: Mandriva 2007.1 Dual Opterons binutils-2.17.50.0.9-1mdv2007.1 gcc-4.1.2-1mdv2007.1 This works as expected: gcc -pg -O0 -g -lm -o fastaproperties fastaproperties.c gunzip -c /usr/common/BLASTDB/dm_dna.nt.gz |./fastaproperties - gprof -l fastaproperties > goo.txt with output like (sorry about the wrap): Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls Ts/call Ts/call name 56.73 0.60 0.60 main (fastaproperties.c:148 @ 8048ddb) 23.84 0.85 0.25 main (fastaproperties.c:147 @ 8048e15) 9.54 0.95 0.10 main (fastaproperties.c:144 @ 8048d8d) 4.29 0.99 0.05 main (fastaproperties.c:147 @ 8048dd2) Whereas for the development nettee: gcc -Wall -DNOUSLEEP -D_LARGEFILE64_SOURCE -D_POSIX_SOURCE -pg -O0 -g -o nettee nettee.c rb.c nio.c ./nettee -v 255 -next monkey01 -in - </usr/common/BLASTDB/dm_dna.nt.gz 2>stderr.log #this copies that largish file to node monkey01 in about 6 seconds gprof -l nettee >foo.txt produces (again, sorry about the wrap): Flat profile: Each sample counts as 0.01 seconds. no time accumulated % cumulative self self total time seconds seconds calls Ts/call Ts/call name 0.00 0.00 0.00 608 0.00 0.00 rb_shadow_set_reconcile (rb.c:427 @ 8051b70) 0.00 0.00 0.00 330 0.00 0.00 writenbytes_noblock_n (nio.c:1267 @ 805579d) 0.00 0.00 0.00 315 0.00 0.00 readnbytes_noblock_n (nio.c:1323 @ 80558a0) 0.00 0.00 0.00 311 0.00 0.00 write_rb_noblock_n (nio.c:1155 @ 80554fc) 0.00 0.00 0.00 297 0.00 0.00 read_rb_noblock_n (nio.c:1105 @ 805537f) This is not very helpful. The program uses a standard sort of network methodology, where it runs in a while loop using FD_SET, runs select, and then reads/writes from/to those inputs/outputs which select has marked as ready. I know the program spends 99% of its time in a routine called transmit(), where all of this work is performed, but transmit is at the very end of the first list and looks like this: 0.00 0.00 0.00 1 0.00 0.00 transmit (nettee.c:1306 @ 804b7b1) I tried transferring a larger file which took 20 seconds, but still all the fields held 0.00 seconds. Here's the older version: gcc -Wall -DNOUSLEEP -D_LARGEFILE64_SOURCE -D_POSIX_SOURCE -pg -g -o -O0 nettee ../nettee-0.1.8/nettee.c ./nettee -v 255 -next monkey01 -in - </usr/common/BLASTDB/am_dna.nt.gz 2>stderr.log gprof -l nettee >foo.txt which looks fine: Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls Ts/call Ts/call name 54.29 0.19 0.19 writenbytes (nettee.c:913 @ 804a30a) 30.00 0.30 0.11 writenbytes (nettee.c:914 @ 804a326) 12.86 0.34 0.05 writenbytes (nettee.c:916 @ 804a32c) 2.86 0.35 0.01 writenbytes (nettee.c:912 @ 804a359) 0.00 0.35 0.00 34071 0.00 0.00 readnbytes (nettee.c:933 @ 804a36a) What could be the problem in the new version of this program which is so confusing gprof? I've run nettee in valgrind and it was well behaved running in there (albeit really slow). Thanks, David Mathog [EMAIL PROTECTED] Manager, Sequence Analysis Facility, Biology Division, Caltech _______________________________________________ bug-binutils mailing list bug-binutils@gnu.org http://lists.gnu.org/mailman/listinfo/bug-binutils
