https://software.intel.com/en-us/articles/pin-a-binary-instrumentation-tool-downloads
Introduction to Intel Pin
This blogpost is an introduction to Intel’s Pin dynamic instrumentation framework. Pin and the pintools were brought to my attention by Mahmoud Hatem in his blogpost Tracing Memory access of an oracle process: Intel PinTools. The Pin framework provides an API that abstracts instruction-set specifics (on the CPU layer). Because this is a dynamic binary instrumentation tool, it requires no recompiling of source code. This means we can use it with programs like the Oracle database executable. The Pin framework download comes with a set of pre-created tools called ‘Pintools’. Some of these tools are really useful for Oracle investigation and research.
Pin works in a very sophisticated way. The description in the Pin manualis to think of Pin as a JIT (just in time) compiler, where the compiler does not take byte code (as JIT compilation does with Java), but the executable of the process pin is executed against. This means pin inserts itself into the process’ execution. This can be seen when looking at the memory map of such a process:
$ cat /proc/29595/maps | grep -e pin-3.0 -e oracle 00400000-1098a000 r-xp 00000000 fb:02 68469986 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle 10b8a000-10bac000 r--p 1058a000 fb:02 68469986 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle 10bac000-10e05000 rw-p 105ac000 fb:02 68469986 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle 7fa01e04c000-7fa01e31d000 r-xp 00000000 fb:04 67152845 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/lib-ext/libpin3dwarf.so 7fa01e51c000-7fa01e530000 r--p 002d0000 fb:04 67152845 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/lib-ext/libpin3dwarf.so 7fa01e530000-7fa01e531000 rw-p 002e4000 fb:04 67152845 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/lib-ext/libpin3dwarf.so 7fa01e533000-7fa01e71a000 r-xp 00000000 fb:04 954267 /home/oracle/pin/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples/obj-intel64/calltrace.so 7fa01e91a000-7fa01e91c000 r--p 001e7000 fb:04 954267 /home/oracle/pin/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples/obj-intel64/calltrace.so 7fa01e91c000-7fa01e91e000 rw-p 001e9000 fb:04 954267 /home/oracle/pin/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples/obj-intel64/calltrace.so 7fa01e946000-7fa01e9c9000 r-xp 00000000 fb:04 136702 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libc-dynamic.so 7fa01e9ca000-7fa01e9cc000 r--p 00083000 fb:04 136702 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libc-dynamic.so 7fa01e9cc000-7fa01e9ce000 rw-p 00085000 fb:04 136702 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libc-dynamic.so 7fa01e9d6000-7fa01ea04000 r-xp 00000000 fb:04 136694 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libm-dynamic.so 7fa01ea04000-7fa01ea05000 r--p 0002d000 fb:04 136694 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libm-dynamic.so 7fa01ea05000-7fa01ea06000 rw-p 0002e000 fb:04 136694 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libm-dynamic.so 7fa01ea06000-7fa01eac4000 r-xp 00000000 fb:04 136696 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libstlport-dynamic.so 7fa01eac5000-7fa01eac8000 r--p 000be000 fb:04 136696 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libstlport-dynamic.so 7fa01eac8000-7fa01eaca000 rw-p 000c1000 fb:04 136696 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libstlport-dynamic.so 7fa01eacb000-7fa01edb7000 r-xp 00000000 fb:04 100663633 /home/oracle/pin/pin-3.0-76991-gcc-linux/extras/xed-intel64/lib/libxed.so 7fa01edb8000-7fa01ee24000 r--p 002ec000 fb:04 100663633 /home/oracle/pin/pin-3.0-76991-gcc-linux/extras/xed-intel64/lib/libxed.so 7fa01ee24000-7fa01ee25000 rw-p 00358000 fb:04 100663633 /home/oracle/pin/pin-3.0-76991-gcc-linux/extras/xed-intel64/lib/libxed.so 7fa01ee80000-7fa01f385000 r-xp 00000000 fb:04 136689 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/bin/pinbin 7fa01f385000-7fa01f38d000 r--p 00504000 fb:04 136689 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/bin/pinbin 7fa01f38d000-7fa01f394000 rw-p 0050c000 fb:04 136689 /home/oracle/pin/pin-3.0-76991-gcc-linux/intel64/bin/pinbin 7fa01f54e000-7fa01f6d4000 r-xp 00000000 fb:02 212053053 /u01/app/oracle/product/12.1.0.2/dbhome_1/lib/libshpkavx12.so 7fa01f6d4000-7fa01f8d3000 ---p 00186000 fb:02 212053053 /u01/app/oracle/product/12.1.0.2/dbhome_1/lib/libshpkavx12.so
Here you see this process an oracle foreground (rows 1-3), after which we see a lot of stuff that pin pushed into the process’ address space.
For this reason, it’s vitally important to use and run pin as the same user as the process you want to run pin against. The way pin works is that, upon execution of pin, the pin executable inserts itself into the process’ address space, gains control and then tries to load necessary libraries. If it can’t find these libraries, it will send a SIGKILL to the process, effectively stopping it!
In order to obtain pin, go to the pin homepage, downloads, linux and select the ‘gcc compiler kit’. This is a zipped tarball. Upload that to a linux server as the database owner, usually ‘oracle’. I created a directory ‘pin’ in which I put the tarball, and extracted it (tar xzf). The next step is to compile the tools that come with pin:
$ cd pin-3.0-76991-gcc-linux/source/tools $ make
This will output a lot of stuff on your screen and compiles everything in the tools directory.
Now that we have seen an introduction, let’s use a Pin tool to do something useful! One such useful is the tool ‘DebugTrace’. First obtain the process id (pid) from an Oracle server foreground process. Then execute the pin tool against this process:
$ pwd /home/oracle/pin/pin-3.0-76991-gcc-linux $ ./pin -pid 2407 -t source/tools/DebugTrace/obj-intel64/debugtrace.so
Upon execution, nothing is returned, because the majority of the things are happening in the process pin is run against (2407 in this case). If no parameters are specified, the pintool will create a file in the current working directory of the process it is run against. For an oracle foreground process, the current working directory is $ORACLE_HOME/dbs:
$ ls -l /proc/2407/cwd lrwxrwxrwx 1 oracle oinstall 0 Nov 17 01:45 /proc/2407/cwd -> /u01/app/oracle/product/12.1.0.2/dbhome_1/dbs
For the sake of testing this, I ran ‘select * from dual’ in the oracle database foreground process.
Let’s look what this produces! This is how my dbs directory looks like:
$ ls -ltr total 2332 -rw-r--r--. 1 oracle oinstall 2992 Feb 3 2012 init.ora -rw-r-----. 1 oracle oinstall 24 Nov 5 09:32 lkTESTDB -rw-r-----. 1 oracle oinstall 7680 Nov 5 09:41 orapwtestdb -rw-r-----. 1 oracle oinstall 57 Nov 5 09:42 inittestdb.ora -rw-rw----. 1 oracle oinstall 1544 Nov 16 09:40 hc_testdb.dat -rw-r--r-- 1 oracle oinstall 2361460 Nov 17 01:49 debugtrace.out
You can see the debugtrace.out file is what is produced by the pin tool, and it look rather big (remember I only ran ‘select * from dual’)!
Let’s look into the file:
$ less debugtrace.out
3 @@@ return underflow
Return 0x00007f706b664218 /lib64/libpthread.so.0:__read_nocancel+0x00000000000f returns: 0x12c
14 @@@ return underflow
Return 0x000000000cefb62d /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:sntpread+0x00000000003d returns: 0
31 @@@ return underflow
Return 0x000000000cefb580 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:ntpfprd+0x0000000000c0 returns: 0
119 @@@ return underflow
Return 0x000000000cedcc9d /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:nsbasic_brc+0x00000000032d returns: 0
122 @@@ return underflow
Return 0x000000000cedc90a /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:nsbrecv+0x00000000005a returns: 0
152 Call 0x000000000ceeb746 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:nioqrc+0x000000000276 -> 0x0000000005b170d0 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:_intel_fast_memcpy(0x7ffeef95c305, 0x7f706ae51da0, ...)
156 Tailcall 0x0000000005b170de /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:_intel_fast_memcpy+0x00000000000e -> 0x0000000005b170c0 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:_intel_fast_memcpy.P(0x7ffeef95c305, 0x7f706ae51da0, ...)
158 | Call 0x0000000005b170c1 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:_intel_fast_memcpy.P+0x000000000001 -> 0x0000000005b1dcb0 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:__intel_ssse3_rep_memcpy(0x7ffeef95c305, 0x7f706ae51da0, ...)
172 | Return 0x0000000005b20097 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:__intel_ssse3_rep_memcpy+0x0000000023e7 returns: 0x7ffeef95c305
174 Return 0x0000000005b170c7 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:_intel_fast_memcpy.P+0x000000000007 returns: 0x7ffeef95c305
197 @@@ return underflow
Return 0x000000000ceeb7ad /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:nioqrc+0x0000000002dd returns: 0
213 Call 0x000000000cb5d8b0 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:opikndf2+0x000000000410 -> 0x000000000c940560 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:kslwtectx(0x7ffeef95c040, 0x7f706ae51da1, ...)
268 | Call 0x000000000c94066e /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:kslwtectx+0x00000000010e -> 0x000000000cd585c0 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:sltrgftime64(0x7ffeef95c040, 0x7f706ae51da1, ...)
278 | | Call 0x000000000cd5863b /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:sltrgftime64+0x00000000007b -> 0x000000000b13ef90 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:sltrgftime64_cgt(0x7ffeef95c040, 0x7f706ae51da1, ...)
286 | | | Call 0x000000000b13efa3 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:sltrgftime64_cgt+0x000000000013 -> 0x0000000000ba6860 /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle:.plt+0x000000001360(0x1, 0x7ffeef95beb0, ...)
293 | | | | Call 0x00007f706b188dcb /lib64/libc.so.6:__clock_gettime+0x00000000001b -> 0x00007ffeef9ab8a0 clock_gettime(0x1, 0x7ffeef95beb0, ...)
...etc...
I think this is rather exciting! This is a FULL function call trace, indented by call depth! The first lines in the trace are returns, and these returns produce a ‘return underflow’, which is because these functions have been called before the trace was put on the process. This trace shows: Calling: the address and function where the function call is made, the address and function that is called and first two arguments of the function. Returning: the address and function where the return is executed, and the returncode. Tailcall: this is a function that is called as the last instruction in the current function. This means it returns as part of the current function, which is shown by not indenting this call further (call, tailcall and return are all indented at the same level).
Please mind currently I am not aware of a way to remove the pin framework and tool from a process address space. Also mind that because of how this works (a lot of intercepting in the execution flow), it will slow down the process significantly. Use this tool and the above described techniques at your own risk.