Using valgrind with parallel VisIt

[markcmiller86]

Did you know you can run valgrind with parallel VisIt. Its a bit combersome but does indeed work and can be very useful. It works by using valgrind's feature to specify the name of the file it sends its messages to. By including the process id in the valgrind file name (which is VisIt's default behavior when using valgrind on a parallel engine), we can ensure that each MPI rank's valgrind process gets its own file to write to.

For example, to debug a recent run on a salloc'd node of rzhound, here is what I did...

% sxterm 1 112 30 -p pdebug # launches a new xterm on the salloc'd node
% # launch VisIt on 16 cores but with also valgrind'ing `engine_par` processes
% ./bin/visit -np 16 -l srun -valgrind engine_par -o /p/lustre1/miller86/silo_periodic_boundary/JUNK05d.g63130.root
% ls vg*.log
vg_engine_par_3016241.log  vg_engine_par_3016245.log  vg_engine_par_3016249.log  vg_engine_par_3016253.log
vg_engine_par_3016242.log  vg_engine_par_3016246.log  vg_engine_par_3016250.log  vg_engine_par_3016254.log
vg_engine_par_3016243.log  vg_engine_par_3016247.log  vg_engine_par_3016251.log  vg_engine_par_3016255.log
vg_engine_par_3016244.log  vg_engine_par_3016248.log  vg_engine_par_3016252.log  vg_engine_par_3016256.log

If you are looking for leaks, you must take care to compile VisIt with -DDEBUG_MEMORY_LEAKS. Otherwise, VisIt is not always nice about cleaning up after itself during exit (it doesn't need to be...its exiting and cleaning up just bogs down the speed of exiting).

grep 'in use at exit:' vg*.log
vg_engine_par_3016241.log:==3016241==     in use at exit: 1,228,872 bytes in 13,160 blocks
vg_engine_par_3016242.log:==3016242==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016243.log:==3016243==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016244.log:==3016244==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016245.log:==3016245==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016246.log:==3016246==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016247.log:==3016247==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016248.log:==3016248==     in use at exit: 493,054 bytes in 3,199 blocks
vg_engine_par_3016249.log:==3016249==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016250.log:==3016250==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016251.log:==3016251==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016252.log:==3016252==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016253.log:==3016253==     in use at exit: 493,014 bytes in 3,198 blocks
vg_engine_par_3016254.log:==3016254==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016255.log:==3016255==     in use at exit: 492,974 bytes in 3,197 blocks
vg_engine_par_3016256.log:==3016256==     in use at exit: 492,974 bytes in 3,197 blocks

The first line in the leak output, above, is likely from the valgrind of MPI rank 0. Usually, that MPI rank does a lot more work to bootstrap everything. In this case, I didn't have -DDEBUG_MEMORY_LEAKS for all of VisIt...just the engine.

If you are just looking for memory, errors, you can use this grep command...

grep -i -e "invalid read" -e "invalid write" -e "use of uninitialised value" -e "definitely lost" \
-e "possibly lost" -e "uninitialised value" -e "overlap" vg*.log

[markcmiller86]

FYI...I happened to be looking at another test, silo_altdriver.py (which just runs the silo.py test but with the alternate driver to whatever the default is...PDB if default is HDF5 and HDF5 is default is PDB).

I happened to see leeks and uninitialized values...

vg_engine_ser_1226669.log.gz

poodle18{miller86}2042: grep -i -e "invalid read" -e "invalid write" -e "use of uninitialised value" -e "definitely lost" -e "uninitialised value" -e "overlap" vg*.log
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a heap allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a heap allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a heap allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a heap allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a heap allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a heap allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a heap allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== Conditional jump or move depends on uninitialised value(s)
==1226669==  Uninitialised value was created by a stack allocation
==1226669== 8 bytes in 1 blocks are definitely lost in loss record 983 of 18,589
==1226669== 8 bytes in 1 blocks are definitely lost in loss record 984 of 18,589
==1226669== 8 bytes in 1 blocks are definitely lost in loss record 985 of 18,589
==1226669== 8 bytes in 1 blocks are definitely lost in loss record 986 of 18,589
==1226669== 26 bytes in 1 blocks are definitely lost in loss record 2,383 of 18,589
==1226669== 26 bytes in 1 blocks are definitely lost in loss record 2,384 of 18,589
==1226669== 28 bytes in 1 blocks are definitely lost in loss record 2,499 of 18,589
==1226669== 28 bytes in 1 blocks are definitely lost in loss record 2,500 of 18,589
==1226669== 101 (48 direct, 53 indirect) bytes in 3 blocks are definitely lost in loss record 13,475 of 18,589
==1226669== 192 bytes in 8 blocks are definitely lost in loss record 14,870 of 18,589
==1226669== 198 (64 direct, 134 indirect) bytes in 1 blocks are definitely lost in loss record 14,872 of 18,589
==1226669== 198 (64 direct, 134 indirect) bytes in 1 blocks are definitely lost in loss record 14,873 of 18,589
==1226669== 200 (176 direct, 24 indirect) bytes in 10 blocks are definitely lost in loss record 14,904 of 18,589
==1226669== 206 (64 direct, 142 indirect) bytes in 1 blocks are definitely lost in loss record 14,914 of 18,589
==1226669== 206 (64 direct, 142 indirect) bytes in 1 blocks are definitely lost in loss record 14,915 of 18,589
==1226669== 216 bytes in 9 blocks are definitely lost in loss record 14,999 of 18,589
==1226669== 300 (264 direct, 36 indirect) bytes in 15 blocks are definitely lost in loss record 16,229 of 18,589
==1226669== 300 (264 direct, 36 indirect) bytes in 15 blocks are definitely lost in loss record 16,230 of 18,589
==1226669== 401 bytes in 1 blocks are definitely lost in loss record 16,841 of 18,589
==1226669== 442 bytes in 1 blocks are definitely lost in loss record 16,891 of 18,589
==1226669== 552 bytes in 23 blocks are definitely lost in loss record 17,146 of 18,589
==1226669== 608 (296 direct, 312 indirect) bytes in 1 blocks are definitely lost in loss record 17,244 of 18,589
==1226669== 696 bytes in 29 blocks are definitely lost in loss record 17,291 of 18,589
==1226669== 843 bytes in 2 blocks are definitely lost in loss record 17,391 of 18,589
==1226669== 859 (104 direct, 755 indirect) bytes in 1 blocks are definitely lost in loss record 17,416 of 18,589
==1226669== 859 (104 direct, 755 indirect) bytes in 1 blocks are definitely lost in loss record 17,417 of 18,589
==1226669== 1,090 (960 direct, 130 indirect) bytes in 54 blocks are definitely lost in loss record 17,629 of 18,589
==1226669== 1,103 (8 direct, 1,095 indirect) bytes in 1 blocks are definitely lost in loss record 17,630 of 18,589
==1226669== 1,243 (104 direct, 1,139 indirect) bytes in 1 blocks are definitely lost in loss record 17,786 of 18,589
==1226669== 1,392 bytes in 58 blocks are definitely lost in loss record 17,864 of 18,589
==1226669== 1,395 (384 direct, 1,011 indirect) bytes in 1 blocks are definitely lost in loss record 17,865 of 18,589
==1226669== 1,395 (384 direct, 1,011 indirect) bytes in 1 blocks are definitely lost in loss record 17,866 of 18,589
==1226669== 1,992 bytes in 83 blocks are definitely lost in loss record 18,055 of 18,589
==1226669== 4,185 (1,200 direct, 2,985 indirect) bytes in 3 blocks are definitely lost in loss record 18,261 of 18,589
==1226669== 4,641 (48 direct, 4,593 indirect) bytes in 1 blocks are definitely lost in loss record 18,284 of 18,589
==1226669== 4,713 (72 direct, 4,641 indirect) bytes in 9 blocks are definitely lost in loss record 18,285 of 18,589
==1226669== 4,936 (400 direct, 4,536 indirect) bytes in 1 blocks are definitely lost in loss record 18,297 of 18,589
==1226669== 5,230 (56 direct, 5,174 indirect) bytes in 1 blocks are definitely lost in loss record 18,304 of 18,589
==1226669== 5,404 (96 direct, 5,308 indirect) bytes in 1 blocks are definitely lost in loss record 18,311 of 18,589
==1226669== 5,405 (296 direct, 5,109 indirect) bytes in 1 blocks are definitely lost in loss record 18,312 of 18,589
==1226669== 5,405 (400 direct, 5,005 indirect) bytes in 1 blocks are definitely lost in loss record 18,313 of 18,589
==1226669== 5,407 (72 direct, 5,335 indirect) bytes in 1 blocks are definitely lost in loss record 18,314 of 18,589
==1226669== 8,520 bytes in 355 blocks are definitely lost in loss record 18,384 of 18,589
==1226669== 11,160 (3,200 direct, 7,960 indirect) bytes in 8 blocks are definitely lost in loss record 18,428 of 18,589
==1226669== 12,555 (3,456 direct, 9,099 indirect) bytes in 9 blocks are definitely lost in loss record 18,444 of 18,589
==1226669== 13,090 (72 direct, 13,018 indirect) bytes in 1 blocks are definitely lost in loss record 18,446 of 18,589
==1226669== 13,664 (40 direct, 13,624 indirect) bytes in 1 blocks are definitely lost in loss record 18,451 of 18,589
==1226669== 14,874 (72 direct, 14,802 indirect) bytes in 1 blocks are definitely lost in loss record 18,463 of 18,589
==1226669== 18,506 (400 direct, 18,106 indirect) bytes in 1 blocks are definitely lost in loss record 18,474 of 18,589
==1226669== 75,648 (2,000 direct, 73,648 indirect) bytes in 5 blocks are definitely lost in loss record 18,542 of 18,589
==1226669== 80,303 (2,400 direct, 77,903 indirect) bytes in 5 blocks are definitely lost in loss record 18,546 of 18,589
==1226669== 137,822 (72 direct, 137,750 indirect) bytes in 1 blocks are definitely lost in loss record 18,565 of 18,589
==1226669== 147,878 (72 direct, 147,806 indirect) bytes in 1 blocks are definitely lost in loss record 18,568 of 18,589
==1226669== 181,024 (800 direct, 180,224 indirect) bytes in 2 blocks are definitely lost in loss record 18,570 of 18,589
==1226669== 263,076 (800 direct, 262,276 indirect) bytes in 2 blocks are definitely lost in loss record 18,573 of 18,589
==1226669==    definitely lost: 34,762 bytes in 741 blocks

[markcmiller86]

BTW...even though the default behavior of a VisIt engine is to NOT cleanup after itself when exiting, a definitely lost record from valgrind is almost certainly a real memory leak in the engine.

[JustinPrivitera]

It would be good to have a valgrind hackathon. Maybe we should bring back hackathons in general.

[markcmiller86]

A valgrind-a-thon. I like it! ❤️