Printout messages from Bits.h ignored

pseyfert · May 23, 2016, 12:18pm

I’m playing with the compression in ROOT
(github.com/pseyfert/root/tree/m … mpressions) and added printout
statements to ZInflate.c just at the beginning of R__unzip and at the beginning
of R__zipMultipleAlgorithm in Bits.h.

To print I use

To see the output I then run this short progam:
github.com/pseyfert/root-compre … convert.cc

(open a root file, and copy the first TTree from the input file to a new root
file with a different compression level)

Strangely, I see the printout from R__unzip, but not that from
R__zipMultipleAlgorithm. Also when checking the intermediate .o files with

strings core/zip/CMakeFiles/Zip.dir/src/ZDeflate.c.oor

strings core/zip/CMakeFiles/Zip.dir/src/ZInflate.c.o
I see my print message only in ZInflate but not in ZDeflate.

Any hints what’s going on?

mato · May 23, 2016, 12:42pm

Bits.h is only included in ZDeflate.c. So, would expect that any modification is only visible in ZDeflate.c.o and this contradicts your claim. Very strange indeed.

pcanal · May 23, 2016, 2:16pm

This is odd. How much of ROOT did you rebuild? R__zipMultipleAlgorithm is used for writing while R__unzip is used for reading.

Cheers,
Philippe.

pseyfert · May 23, 2016, 2:33pm

I’m glad we agree on the strangeness.

Well in my latest desparate attempt I deleted the entire build directory and started from

I then ran

make Core

and (to be reasonably sure ccache isn’t tricking me) deleted ZInflate.c.o and ZDeflate.c.o, ran make -n Core to see the compiler command and then build the two by hand without ccache in the command:

/usr/bin/cc   -pipe -m64 -Wall -W -fPIC -pthread -DBROTLI -DZOPFLI -DLZ4 -DLZO -O2 -g -DNDEBUG -fPIC -I/home/pseyfert/coding/recentroot/build_lzo/include    -o CMakeFiles/Zip.dir/src/ZInflate.c.o   -c /home/pseyfert/coding/ROOT6/core/zip/src/ZInflate.c
/usr/bin/cc   -pipe -m64 -Wall -W -fPIC -pthread -DBROTLI -DZOPFLI -DLZ4 -DLZO -O2 -g -DNDEBUG -fPIC -I/home/pseyfert/coding/recentroot/build_lzo/include    -o CMakeFiles/Zip.dir/src/ZDeflate.c.o   -c /home/pseyfert/coding/ROOT6/core/zip/src/ZDeflate.c

and from there on the usual make -j4 && make install

(using what’s now on github github.com/pseyfert/root/tree/m … mpressions)

pcanal · May 23, 2016, 2:40pm

Hi,

I suspect that there is a run-time environment issues … Nonetheless I recommend that you rebuild in debug mode and use gdb to trace down whether things go wrong.

Cheers,
Philippe.

mato · May 23, 2016, 3:57pm

What ROOT version are you using? The configuration options -Dlzo=on -Dbuiltin-lz4=on -Dlz4=on -Dzopfli=on are completely new to me.

pseyfert · May 23, 2016, 4:24pm

well that’s what i’m working on and matches the github branch i linked to.
I branched off the master at 30150b5897a66f78833405c11fb0cf6e0304ac5c https://github.com/root-mirror/root/compare/master…pseyfert:master_compressions?expand=1

Though I now also tried going back to the master (i.e. rm’ing the build and install directory) to see what happens when i only add the printout. Still without success.
(see a much quicker to read diff here github.com/root-mirror/root/com … 1?expand=1)

Running through gdb confused me even more. Running until a breakpoint at R__zipMultipleAlgorithms and then stepping forward I see my printout getting called (and then the calls to __find_specmb, _IO_vfprintf_internal, __IO_vsprintf, __sprintf,…) but not the actual printout.

(gdb) bt
#0  strchrnul () at ../sysdeps/x86_64/strchr.S:27
#1  0x00007ffff3cd2f29 in __find_specmb (format=0x7ffff7a5c539 "") at printf-parse.h:108
#2  _IO_vfprintf_internal (s=s@entry=0x7ffffffcdab0, format=<optimized out>, 
    format@entry=0x7ffff7a5c52a "size of tgt: %d", ap=ap@entry=0x7ffffffcdbd8) at vfprintf.c:1669
#3  0x00007ffff3cf53fb in __IO_vsprintf (string=0x7ffffffcdcb0 "size of tgt: 21440", 
    format=0x7ffff7a5c52a "size of tgt: %d", args=args@entry=0x7ffffffcdbd8) at iovsprintf.c:42
#4  0x00007ffff3cd9eb7 in __sprintf (s=s@entry=0x7ffffffcdcb0 "size of tgt: 21440", 
    format=format@entry=0x7ffff7a5c52a "size of tgt: %d") at sprintf.c:32
#5  0x00007ffff797605a in pauls_diagnose (cxlevel=<optimized out>, srcsize=0x7fffffffde4c, 
    src=0xb614479 "?\240y\336>&\315\325>\244\037\230?%\302\204>\377\324u?v\001.?d\325\f? \343\237?x\036\202?\213\323\001>\213", tgtsize=0x7fffffffde4c, 
    tgt=0x11e65ba9 "\263\264\250l,\200?ّ%'\233%H?\337\\\223\003\303T\370?\325\310\022v\330\035\304?\337\327\025\230\037\265\270?\345l\316m\261\375\250?\344\341\020(\033M\312?\332\033\257\327\a|\b?\316g\004\321\005\263\220?\341\347`\034䯠?\241ٗ\212R-", irep=<optimized out>) at /home/pseyfert/coding/ROOT6/core/zip/src/Bits.h:54
#6  0x00007ffff7977c10 in R__zipMultipleAlgorithm (cxlevel=2, srcsize=0x7fffffffde4c, 
    src=0xb614479 "?\240y\336>&\315\325>\244\037\230?%\302\204>\377\324u?v\001.?d\325\f? \343\237?x\036\202?\213\323\001>\213", tgtsize=0x7fffffffde4c, 
    tgt=0x11e65ba9 "\263\264\250l,\200?ّ%'\233%H?\337\\\223\003\303T\370?\325\310\022v\330\035\304?\337\327\025\230\037\265\270?\345l\316m\261\375\250?\344\341\020(\033M\312?\332\033\257\327\a|\b?\316g\004\321\005\263\220?\341\347`\034䯠?\241ٗ\212R-", irep=0x7fffffffde48, compressionAlgorithm=6)
    at /home/pseyfert/coding/ROOT6/core/zip/src/Bits.h:631
#7  0x00007ffff5f3fec0 in TBasket::WriteBuffer (this=0xd3599d0)
    at /home/pseyfert/coding/ROOT6/tree/tree/src/TBasket.cxx:1014
#8  0x00007ffff5f0c293 in TBranch::WriteBasket (this=this@entry=0xa6c6130, basket=basket@entry=0xd3599d0, 
    where=0) at /home/pseyfert/coding/ROOT6/tree/tree/src/TBranch.cxx:2600
#9  0x00007ffff5f0cbc4 in TBranch::Fill (this=0xa6c6130)
    at /home/pseyfert/coding/ROOT6/tree/tree/src/TBranch.cxx:811
#10 0x00007ffff5ee3fe1 in TTree::Fill (this=0x7448510)
    at /home/pseyfert/coding/ROOT6/tree/tree/src/TTree.cxx:4389
#11 0x00007ffff5ee36ac in TTree::CopyEntries (this=0x7448510, tree=0x1095dd0, nentries=4239, 
    option=0x40112b "") at /home/pseyfert/coding/ROOT6/tree/tree/src/TTree.cxx:3489
#12 0x00007ffff5ee2e9a in TTree::CloneTree (this=0x1095dd0, nentries=4294967295, option=0x40112b "")
    at /home/pseyfert/coding/ROOT6/tree/tree/src/TTree.cxx:3145
#13 0x0000000000400edf in convert (alg=6, level=2) at convert.cc:17
#14 0x0000000000400fc0 in main (argc=3, argv=0x7fffffffe428) at convert.cc:30

pcanal · May 23, 2016, 4:38pm

#4 0x00007ffff3cd9eb7 in __sprintf

So it seems you are printing to a string … not stdout or stderrr.

Cheers
Philippe.

pseyfert · May 23, 2016, 5:20pm

hmmmmm, indeed in bug hunting I converted to

[code]+ char buffer[50];

sprintf(buffer,“invocation count = %d”,invocations);
R__error(buffer);
[/code]
switching to

fprintf(stderr,"....") indeed creates the printout. Not sure what problem made me go to the sprintf+R__error way in the first place. There must be something else I did wrong in the first place but can’t reproduce now.