Tracing Memory access of an oracle process : Intel PinTools

This blog post is motivated by a conversation with Frits Hoogland on his great blog post The curious case of the missing semctl call about how he managed to find  a useful memory address (suspecting a fixed SGA variable) used by a process in his investigation.So here i will show how we can easily generates a trace of all/range of memory addresses referenced by a program with an acceptable overhead.

For that we are going to use a Binary Instrumentation Tool named Pin.Pin is basically a tool to insert arbitrary code (written in C or C++) in arbitrary places in the executable. The code is added dynamically while the executable is running.

What is interesting is that Pin allow as to us to instrument only a class of instructions like memory operations by using the Pin API which includes functions that classify and examine instructions.For more info please check :

Using PinTools we can trace all/range of memory  references inside a program by attaching to the running process.

Time for testing : (OEL6/UEK4/ORACLE 12.1.0.2.6)

  1. Download pin tools and install it as user oracle (as of UPDATE 17/11/2016 )
  2. Build the sample tool for memory reference tracing (  cd source/tools/SimpleExamples   make obj-intel64/pinatrace.so )
  3. Test it using the root/oracle user :

../../../pin -t obj-intel64/pinatrace.so — /bin/ls

UPDATE 17/11/2016 : The owner of the instrumented program (target to attach to) need to access some files from the pin directory like (pinbin,linker,etc) so to trace the oracle executable (owner oracle) using the root user for example  execute the following command after installing pin :”chown -R oracle pin_tools/pin-3.0-76991-gcc-linux” or simply install pin using the oracle user (if the instrumented program don’t have access to some files in the pin directory you will receive the following misleading  error “E: Pin loader can’t open file /app/oracle/12.1.0/dbhome_1/bin/oracle: Permission denied”).

UPDATE 17/11/2016 : Good introduction to Intel Pin by Frits Hoogland :  Introduction to Intel Pin

Let’s try how we can find the address “0x60027e20” referenced inside “ksaamb” using PIN tools.(as found by Frits Hoogland) .

Using gdb we can verify that with our test case (deleting one line from a table followed by a commit) this address is accessed 4 time (3 reads/1 writes):

capture-01

Using pin tools  (The test case took less that 2 sec to run and display all the memory address referenced) :

/pin-3.0-76991-gcc-linux/pin -pid 9266  -t  /pin-3.0-76991-gcc-linux/source/tools/SimpleExamples/obj-intel64/pinatrace.so

capture-02

We have the memory address and it’s content and also from where it’s was referenced (Instruction pointer). Using addr2line we can display the actual symbol name :

capture-04

Extract from the memory trace file :

capture-03

This was a very simple example using a ready to use sample tools.More complex plugin can be written depending on the needs.

That’s it 😀

13 thoughts on “Tracing Memory access of an oracle process : Intel PinTools

  1. Hi, I downloaded the pin tools, and tried using pinatrace.so. However, whenever I do that, the foreground session I try to attach to crashes (silently), and the pin executable errors with the message: Pin loader can’t open file /u01/app/oracle/product/12.1.0.2/dbhome_1/bin/oracle: Permission denied.
    (oracle 12.1.0.2.181016, OL7.2 UEK4)

    • Here is an extract from my current configuration :

      [root@svltest dbs]# lsb_release -a
      LSB Version: :base-4.0-amd64:base-4.0-noarch:core-4.0-amd64:core-4.0-noarch:graphics-4.0-amd64:graphics-4.0-noarch:printing-4.0-amd64:printing-4.0-noarch
      Distributor ID: OracleServer
      Description: Oracle Linux Server release 6.6
      Release: 6.6
      Codename: n/a

      [root@svltest dbs]# uname -r
      4.1.12-32.1.2.el6uek.x86_64

      [root@svltest dbs]# ps -ef | grep pmon
      oracle 5405 1 0 Nov07 ? 00:00:29 asm_pmon_+ASM
      oracle 14230 1 0 08:24 ? 00:00:00 ora_pmon_testdb
      root 14630 11693 0 08:24 pts/0 00:00:00 grep pmon

      [root@svltest dbs]# /tmp/pin_tools/pin-3.0-76991-gcc-linux/pin -pid 14230 -t /tmp/pin_tools/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples/obj-intel64/pinatrace.so

      [root@svltest dbs]# /tmp/pin_tools/pin-3.0-76991-gcc-linux/pin -pid 14230 -t /tmp/pin_tools/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples/obj-intel64/pinatrace.so
      E: Attach to pid 14230 failed, Pin is already attached

      [root@svltest dbs]# pwd
      /app/oracle/12.1.0/dbhome_1/dbs

      [root@svltest dbs]# head -5 pinatrace.out
      #
      # Memory Access Trace Generated By Pin
      #
      0x0000003375ceb173: R 0x0000003375f8dfa8 8 0xfffffffffffce448
      0x0000003375ceb17f: W 0x00007fcf69e7b6a8 4 0xb

      [root@svltest dbs]# ll /app/oracle/12.1.0/dbhome_1/bin/oracle
      -rwsr-s–x. 1 oracle dba 323800097 Nov 16 2015 /app/oracle/12.1.0/dbhome_1/bin/oracle

  2. It still doesn’t work. When running it with a command following — it works. But *anything* to which I try to attach the pin executable using -pid gets a sigkill, and pin says it can’t find the executable. Not only oracle, but also ping or tracepath. One additional caveat is I am running this in virtual box.

  3. Sorry, you are right indeed i have done another thing that seem to me at first useless but after some testing it appeared to be the solution to the problem (very ugly solution by the way more investigation is needed) :

    [root@svltest SimpleExamples]# cd /tmp/pintools

    [root@svltest pintools]# tar -xzf pin-3.0-76991-gcc-linux.tar.gz

    [root@svltest pintools]# cd /tmp/pintools/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples

    [root@svltest SimpleExamples]# make obj-intel64/pinatrace.so

    [root@svltest SimpleExamples]# ps -ef | grep pmon
    oracle 5405 1 0 Nov07 ? 00:00:31 asm_pmon_+ASM
    oracle 25453 1 0 15:09 ? 00:00:00 ora_pmon_testdb
    root 25606 11693 0 15:09 pts/0 00:00:00 grep pmon

    [root@svltest SimpleExamples]# ../../../pin -pid 25453 -t obj-intel64/pinatrace.so
    E: Pin loader can’t open file /app/oracle/12.1.0/dbhome_1/bin/oracle: Permission denied

    The process was killed as you !

    [root@svltest SimpleExamples]# cd /tmp/pintools

    [root@svltest pintools]# chmod -R 777 pin-3.0-76991-gcc-linux

    [root@svltest pintools]# cd /tmp/pintools/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples

    [root@svltest SimpleExamples]# ps -ef | grep pmon
    oracle 5405 1 0 Nov07 ? 00:00:31 asm_pmon_+ASM
    oracle 25857 1 0 15:10 ? 00:00:00 ora_pmon_testdb
    root 26315 11693 0 15:10 pts/0 00:00:00 grep pmon

    [root@svltest SimpleExamples]# ../../../pin -pid 25857 -t obj-intel64/pinatrace.so
    [root@svltest SimpleExamples]# ../../../pin -pid 25857 -t obj-intel64/pinatrace.so
    E: Attach to pid 25857 failed, Pin is already attached

    [root@svltest dbs]# cd /app/oracle/12.1.0/dbhome_1/dbs
    [root@svltest dbs]# head -10 pinatrace.out
    #
    # Memory Access Trace Generated By Pin
    #
    0x0000003375ceb173: R 0x0000003375f8dfa8 8 0xfffffffffffce448

    Now it work there is apparently some file permission missing somewhere ,more investigation is needed but this is the very dirty way .(The thing about setuid and setgid was only some garbage from my memory so i will delete the comment sorry)

    • Apparently the owner of the program to be instrumented (exemple oracle) need to have access to some files (still need to be determined) in the pin tools directory so the error message is misleading !

      • Using systemtap i attached to the program to be instrumented before running pintools to show syscalls and in fact we can see that some file need to be accessed from the pin directory :

        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/bin/pinbin”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/linker”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libxed.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/lib-ext/libxed.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/extras/xed-intel64/lib/libxed.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libstlport-dynamic.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libm-dynamic.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libc-dynamic.so”, O_RDONLY
        open “/proc/sys/kernel/osrelease”, O_RDONLY
        open “/dev/pts/0”, O_WRONLY|O_CREAT|O_APPEND, 0666
        open “/usr/lib64/qt-3.3/bin/obj-intel64/pinatrace.so”, O_RDONLY
        open “/usr/local/sbin/obj-intel64/pinatrace.so”, O_RDONLY
        open “/usr/local/bin/obj-intel64/pinatrace.so”, O_RDONLY
        open “/sbin/obj-intel64/pinatrace.so”, O_RDONLY
        open “/bin/obj-intel64/pinatrace.so”, O_RDONLY
        open “/usr/sbin/obj-intel64/pinatrace.so”, O_RDONLY
        open “/usr/bin/obj-intel64/pinatrace.so”, O_RDONLY
        open “/root/bin/obj-intel64/pinatrace.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/obj-intel64/pinatrace.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/lib-ext/obj-intel64/pinatrace.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/extras/xed-intel64/lib/obj-intel64/pinatrace.so”, O_RDONLY
        open “/home/oracle/obj-intel64/pinatrace.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples/obj-intel64/pinatrace.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples/obj-intel64/pinatrace.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/runtime/pincrt/libpin3dwarf.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/intel64/lib-ext/libpin3dwarf.so”, O_RDONLY
        open “/tmp/pin_tools/pin-3.0-76991-gcc-linux/source/tools/SimpleExamples/obj-intel64/pinatrace.so”, O_RDONLY
        open “pinatrace.out”, O_WRONLY|O_CREAT|O_TRUNC, 0666

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s