This post explores my troubles with integrating DTrace in projects. I spent a few days searching for and fixing bugs in DTrace. I’ll explain my troubles and approach to fixing bugs in tarantool, a no-sql DB, with common instruments.

This post isn’t yet complete. I’ll add new information after fix/found bugs.

Instruments to research:

OSs:

• FreeBSD 9.1-RELEASE-p7
• Darwin 12.5.0
• Linux 3.8.13-16.el6uek.x86_64 (Oracle Linux)

Solaris based:

• OpenIndiana 151a8 (so old compilers)
• Oracle Linux 11.1 (so old compilers)
• SmartOS latest (all stuff got coredump)

DTrace Versions:

• dtrace: Sun D 1.7 (FreeBSD)
• dtrace: Sun D 1.6.2 (Darwin)
• dtrace: Sun D 1.6.3 (Oracle Linux)

Generate DTrace object twice

%> sudo dtrace -l -m tarantool_box
Password:
   ID   PROVIDER            MODULE                          FUNCTION NAME
dtrace: failed to match :tarantool_box::: No probe matches description

If you have a modular application you’ll try to generate many dtrace objects to link that with the application. You get static libraries and then link. This is a common approach to programming but if you use DTrace in more than one library you need run dtrace -G to get one dtrace object which include all providers.

After the first time you get a dtrace object with correct information but you would like to get object for all providers in different libs in one object. I’ll explain the main issue with second generation with an example.

This is an example with one library. You are able to do this on the command line for getting incorrect object because you did correct object before with information about one: ***

%> dtrace -G -s ../../include/dtrace.d ../CMakeFiles/cjson.dir/third_party/lua-cjson/lua_cjson.c.o -o cjson_dtrace_second.o

%> md5 cjson_dtrace.o
MD5 (cjson_dtrace.o) = 69cc9d1037f106e682464af05205458c
%> md5 cjson_dtrace_second.o
MD5 (cjson_dtrace_second.o) = a42c72ae540be068243936afe2d7b868

On above list you see mismatched md5 sums. When I found that I started fire to drill-down to object files and look at what’s incorrect.

I got 2 dtrace objects, Using the strings command I found the differences:

%> strings -a cjson_dtrace_second.o > dtrace_second
%> strings -a cjson_dtrace.o > dtrace

%> diff -up dtrace dtrace_second

I saw removed functions with dtrace defines for a trace.

--- dtrace  2013-09-27 13:47:17.839671510 +0000
+++ dtrace_second   2013-09-27 13:47:08.717669720 +0000
@@ -117,15 +117,10 @@ vfprintf
 encode-done
 char *
 char *
-json_encode
-$dtrace140912.json_encode
 encode-start
 char *
 char *
-json_encode
-$dtrace140912.json_encode
 new-entry
-luaopen_cjson
 tick-start
 tick-stop
 tarantool

In the next stage I looked inside .SUNW_dof in section of dtrace object file.

%> objdump -s -j .SUNW_dof cjson_dtrace.o

This is correct hex output from dtrace object:

cjson_dtrace.o:     file format elf64-x86-64-freebsd

Contents of section .SUNW_dof:
 0270 00000000 00000000 00000000 05000000  ................
 0280 01000000 00656e63 6f64652d 646f6e65  .....encode-done
 0290 00696e74 00636861 72202a00 696e7400  .int.char *.int.
 02a0 63686172 202a006a 736f6e5f 656e636f  char *.json_enco
 02b0 64650024 64747261 63653134 30393132  de.$dtrace140912
 02c0 2e6a736f 6e5f656e 636f6465 00656e63  .json_encode.enc
 02d0 6f64652d 73746172 7400696e 74006368  ode-start.int.ch
 02e0 6172202a 00696e74 00636861 72202a00  ar *.int.char *.
 02f0 6a736f6e 5f656e63 6f646500 24647472  json_encode.$dtr
 0300 61636531 34303931 322e6a73 6f6e5f65  ace140912.json_e
 0310 6e636f64 65006e65 772d656e 74727900  ncode.new-entry.
 0320 6c75616f 70656e5f 636a736f 6e007469  luaopen_cjson.ti
 0330 636b2d73 74617274 00696e74 00696e74  ck-start.int.int
 0340 00746963 6b2d7374 6f700069 6e740069  .tick-stop.int.i
 0350 6e740074 6172616e 746f6f6c 00000000  nt.tarantool....
 0360 53756e20 4420312e 37004672 65654253  Sun D 1.7.FreeBS
 0370 44000000 00000000 00000000 00000000  D...............
 0380 00000000 00000000 00000000 00000000  ................

Drill-down to next incorrect object:

%> objdump -s -j .SUNW_dof cjson_dtrace_second.o

In .SUNW_dof sect I saw empty dtrace providers for tracing function:

cjson_dtrace_second.o:     file format elf64-x86-64-freebsd

Contents of section .SUNW_dof:
 0190 00000000 00000000 00000000 05000000  ................
 01a0 01000000 00656e63 6f64652d 646f6e65  .....encode-done
 01b0 00696e74 00636861 72202a00 696e7400  .int.char *.int.
 01c0 63686172 202a0065 6e636f64 652d7374  char *.encode-st
 01d0 61727400 696e7400 63686172 202a0069  art.int.char *.i
 01e0 6e740063 68617220 2a006e65 772d656e  nt.char *.new-en
 01f0 74727900 7469636b 2d737461 72740069  try.tick-start.i
 0200 6e740069 6e740074 69636b2d 73746f70  nt.int.tick-stop
 0210 00696e74 00696e74 00746172 616e746f  .int.int.taranto
 0220 6f6c0000 00000000 53756e20 4420312e  ol......Sun D 1.
 0230 37004672 65654253 44000000 00000000  7.FreeBSD.......
 0240 00000000 00000000 00000000 00000000  ................

The next step is finding differences in library objects. After running dtrace -G twice I get these changes in main library objects:

%> md5 lua_cjson.c.o
MD5 (lua_cjson.c.o) = bdc0afbb0869f7bee70c29a7ba538127
%> md5 lua_cjson.c.o.dtrace
MD5 (lua_cjson.c.o.dtrace) = 0d65212c87350dceb64f71429b72ce3b

I looked at the .text section of the object file in objdump because this section contains the executible code.

%> objdump -d -j .text lua_cjson.c.o.dtrace > dtrace
%> objdump -d -j .text lua_cjson.c.o > non-dtrace