Tuesday Dec 10, 2013

Tracing PHP with DTrace - Five Minute Lightning Talk is on Youtube

I gave a 5 minute talk on DTrace in PHP at the SF PHP Meetup Lightning Talk session last night. You can watch it here. It starts at the 14:10 mark.

Tuesday Dec 03, 2013

DTrace and Perl from @GregoryGuillou

Grégory Guillou (@GregoryGuillou) has a post on using DTrace with Perl: Custom DTrace Probes for Perl on Oracle Linux 6. He uses libusdt developed by Chris Andrews (@chrisandrews). Check it out!

Monday Dec 02, 2013

PHP Examples in New "Oracle Linux 6 DTrace Tutorial"

My colleague, Gavin Bowe, has released a new Oracle Linux 6 DTrace Tutorial. It is available in HTML, PDF and ePub from http://docs.oracle.com/cd/E37670_01/index.html.

Chapter 3 on "Tracing User-Space Applications" has some PHP examples.

Tuesday Nov 05, 2013

Tracing Silex from PHP to the OS with DTrace

In this blog post I show the full stack tracing of Brendan Gregg's php_syscolors.d script in the DTrace Toolkit. The Toolkit contains a dozen very useful PHP DTrace scripts and many more scripts for other languages and the OS.

For this example, I'll trace the PHP micro framework Silex, which was the topic of the second of two talks by Dustin Whittle at a recent SF PHP Meetup. His slides are at Silex: From Micro to Full Stack.

Installing DTrace and PHP

The php_syscolors.d script uses some static PHP probes and some kernel probes. For Oracle Linux I discussed installing DTrace and PHP in DTrace PHP Using Oracle Linux 'playground' Pre-Built Packages. On other platforms with DTrace support, follow your standard procedures to enable DTrace and load the correct providers. The sdt and systrace providers are required in addition to fasttrap.

On Oracle Linux, I loaded the DTrace modules like:

# modprobe fasttrap
# modprobe sdt
# modprobe systrace
# chmod 666 /dev/dtrace/helper

Installing the DTrace Toolkit

I download DTraceToolkit-0.99.tar.gz and extracted it:

$ tar -zxf DTraceToolkit-0.99.tar.gz

The PHP scripts are in the Php directory and examples in the Examples directory.

Installing Silex

I downloaded the "fat" Silex .tgz file from the download page and extracted it:

$ tar -zxf silex_fat.tgz

I changed the demonstration silex/web/index.php so I could use the PHP development web server:

<?php

// web/index.php

$filename = __DIR__.preg_replace('#(\?.*)$#', '', $_SERVER['REQUEST_URI']);
if (php_sapi_name() === 'cli-server' && is_file($filename)) {
    return false;
}

require_once __DIR__.'/../vendor/autoload.php';

$app = new Silex\Application();

//$app['debug'] = true;

$app->get('/hello', function() {
        return 'Hello!';
    });

$app->run();

?>

Running DTrace

The php_syscolors.d script uses the -Z option to dtrace, so it can be started before PHP, i.e. when there are zero of the requested probes available to be traced. I ran DTrace like:

# cd DTraceToolkit-0.99/Php
# ./php_syscolors.d

Next, I started the PHP developer web server in a second terminal:

$ cd silex
$ php -S localhost:8080 -t web web/index.php

At this point, the web server is idle, waiting for requests. DTrace is idle, waiting for the probes in php_syscolors.d to be fired, at which time the action associated with each probe will run.

I then loaded the demonstration page in a browser:

http://localhost:8080/hello

When the request was fulfilled and the simple output of "Hello" was displayed, I ^C'd php and dtrace in their terminals to stop them.

DTrace output over a thousand lines long had been generated. Here is one snippet from when run() was invoked:

C    PID/TID   DELTA(us)              FILE:LINE TYPE     -- NAME
...
1   4765/4765         21   Application.php:487  func     -> run
1   4765/4765         29   ClassLoader.php:182  func       -> loadClass
1   4765/4765         17   ClassLoader.php:198  func         -> findFile
1   4765/4765         31                 ":-    syscall        -> access
1   4765/4765         26                 ":-    syscall        <- access
1   4765/4765         16   ClassLoader.php:198  func         <- findFile
1   4765/4765         25                 ":-    syscall      -> newlstat
1   4765/4765         15                 ":-    syscall      <- newlstat
1   4765/4765         13                 ":-    syscall      -> newlstat
1   4765/4765         13                 ":-    syscall      <- newlstat
1   4765/4765         22                 ":-    syscall      -> newlstat
1   4765/4765         14                 ":-    syscall      <- newlstat
1   4765/4765         15                 ":-    syscall      -> newlstat
1   4765/4765         60                 ":-    syscall      <- newlstat
1   4765/4765         13                 ":-    syscall      -> newlstat
1   4765/4765         13                 ":-    syscall      <- newlstat
1   4765/4765         20                 ":-    syscall      -> open
1   4765/4765         16                 ":-    syscall      <- open
1   4765/4765         26                 ":-    syscall      -> newfstat
1   4765/4765         12                 ":-    syscall      <- newfstat
1   4765/4765         17                 ":-    syscall      -> newfstat
1   4765/4765         12                 ":-    syscall      <- newfstat
1   4765/4765         12                 ":-    syscall      -> newfstat
1   4765/4765         12                 ":-    syscall      <- newfstat
1   4765/4765         20                 ":-    syscall      -> mmap
1   4765/4765         14                 ":-    syscall      <- mmap
1   4765/4765       3201                 ":-    syscall      -> mmap
1   4765/4765         27                 ":-    syscall      <- mmap
1   4765/4765       1233                 ":-    syscall      -> munmap
1   4765/4765         53                 ":-    syscall      <- munmap
1   4765/4765         15                 ":-    syscall      -> close
1   4765/4765         13                 ":-    syscall      <- close
1   4765/4765         34       Request.php:32   func         -> main
1   4765/4765         22       Request.php:32   func         <- main
1   4765/4765         31   ClassLoader.php:182  func       <- loadClass
1   4765/4765         33       Request.php:249  func       -> createFromGlobals
1   4765/4765         29       Request.php:198  func         -> __construct
1   4765/4765         24       Request.php:218  func           -> initialize
1   4765/4765         26   ClassLoader.php:182  func             -> loadClass
1   4765/4765         89   ClassLoader.php:198  func               -> findFile
1   4765/4765         43                 ":-    syscall              -> access
...

The output shows PHP functions being called and returning (and where they are located) and which system calls the PHP functions in turn invoked. The time each line took from the previous one is displayed in the third column.

The first column is the CPU number. In this example, the process was always on CPU 1 so the output is naturally ordered without requiring post-processing, or the D script requiring to be modified to display a time stamp.

On a terminal, the output of php_syscolors.d is color-coded according to whether each function is a PHP or system one, hence the file name.

Summary

With one tool, I was able to trace the interaction of a user application with the operating system. I was able to do this to an application running "live" in a web context.

The DTrace Toolkit provides a very handy repository of DTrace information. Even though the PHP scripts were created in the time frame of the original PHP DTrace PECL extension, which only had PHP function entry and return probes, the scripts provide core examples for custom investigation and resolution scripts. You can easily adapt the ideas and create scripts using the other PHP static probes, which are listed in the PHP Manual.

Because DTrace is "always on", you can take advantage of it to resolve development questions or fix production situations.

Friday Nov 01, 2013

DTracing a PHPUnit Test: Looking at Functional Programming

Here's a quick example of using DTrace Dynamic Tracing to work out what a PHP code base does.

I was reading the article Functional Programming in PHP by Patkos Csaba and wondering how efficient this type of programming is. I thought this would be a good time to fire up DTrace and see what is going on. Since DTrace is "always available" even in production machines (once PHP is compiled with --enable-dtrace), this was easy to do.

I have Oracle Linux with the UEK3 kernel and PHP 5.5 with DTrace static probes enabled, as described in DTrace PHP Using Oracle Linux 'playground' Pre-Built Packages

I installed the Functional Programming sample code and Sebastian Bergmann's PHPUnit. Although PHPUnit is included in the Functional Programming example, I found it easier to separately download and use its phar file:

cd ~/Desktop
wget -O master.zip \
  https://github.com/tutsplus/functional-programming-in-php/archive/master.zip
wget https://phar.phpunit.de/phpunit.phar
unzip master.zip

I created a DTrace D script functree.d:

#pragma D option quiet

self int indent;

BEGIN
{
  topfunc = $1;
}

php$target:::function-entry
/copyinstr(arg0) == topfunc/
{
  self->follow = 1;
}

php$target:::function-entry
/self->follow/
{
  self->indent += 2;
  printf("%*s %s%s%s\n", self->indent, "->", arg3?copyinstr(arg3):"", 
                            arg4?copyinstr(arg4):"", copyinstr(arg0));
}

php$target:::function-return
/self->follow/
{
  printf("%*s %s%s%s\n", self->indent, "<-", arg3?copyinstr(arg3):"", 
                            arg4?copyinstr(arg4):"", copyinstr(arg0));
  self->indent -= 2;
}

php$target:::function-return
/copyinstr(arg0) == topfunc/
{
  self->follow = 0;
}

This prints a PHP script function call tree starting from a given PHP function name. This name is passed as a parameter to DTrace, and assigned to the variable topfunc when the DTrace script starts. With this D script, choose a PHP function that isn't recursive, or modify the script to set self->follow = 0 only when all calls to that function have unwound.

From looking at the sample FunSets.php code and its PHPUnit test driver FunSetsTest.php, I settled on one test function to trace:

function testUnionContainsAllElements() {
  ...
}

I invoked DTrace to trace function calls invoked by this test with

# dtrace -s ./functree.d -c 'php phpunit.phar \
 functional-programming-in-php-master/FunSets/Tests/FunSetsTest.php' \
 '"testUnionContainsAllElements"'

The core of this command is a call to PHP to run PHPUnit on the FunSetsTest.php script. Outside that, DTrace is called and the PID of PHP is passed to the D script $target variable so the probes fire just for this invocation of PHP.

Note the quoting around the PHP function name passed to DTrace. The parameter must have double quotes included so DTrace knows it is a string.

The output is:

PHPUnit 3.7.28 by Sebastian Bergmann.

......-> FunSetsTest::testUnionContainsAllElements
  -> FunSets::singletonSet
  <- FunSets::singletonSet
  -> FunSets::singletonSet
  <- FunSets::singletonSet
  -> FunSets::union
  <- FunSets::union
  -> FunSets::contains
    -> FunSets::{closure}
      -> FunSets::contains
        -> FunSets::{closure}
        <- FunSets::{closure}
      <- FunSets::contains
    <- FunSets::{closure}
  <- FunSets::contains
  -> PHPUnit_Framework_Assert::assertTrue
    -> PHPUnit_Framework_Assert::isTrue
    <- PHPUnit_Framework_Assert::isTrue
    -> PHPUnit_Framework_Assert::assertThat
      -> PHPUnit_Framework_Constraint::count
      <- PHPUnit_Framework_Constraint::count
      -> PHPUnit_Framework_Constraint::evaluate
        -> PHPUnit_Framework_Constraint_IsTrue::matches
        <- PHPUnit_Framework_Constraint_IsTrue::matches
      <- PHPUnit_Framework_Constraint::evaluate
    <- PHPUnit_Framework_Assert::assertThat
  <- PHPUnit_Framework_Assert::assertTrue
  -> FunSets::contains
    -> FunSets::{closure}
      -> FunSets::contains
        -> FunSets::{closure}
        <- FunSets::{closure}
      <- FunSets::contains
      -> FunSets::contains
        -> FunSets::{closure}
        <- FunSets::{closure}
      <- FunSets::contains
    <- FunSets::{closure}
  <- FunSets::contains
  -> PHPUnit_Framework_Assert::assertTrue
    -> PHPUnit_Framework_Assert::isTrue
    <- PHPUnit_Framework_Assert::isTrue
    -> PHPUnit_Framework_Assert::assertThat
      -> PHPUnit_Framework_Constraint::count
      <- PHPUnit_Framework_Constraint::count
      -> PHPUnit_Framework_Constraint::evaluate
        -> PHPUnit_Framework_Constraint_IsTrue::matches
        <- PHPUnit_Framework_Constraint_IsTrue::matches
      <- PHPUnit_Framework_Constraint::evaluate
    <- PHPUnit_Framework_Assert::assertThat
  <- PHPUnit_Framework_Assert::assertTrue
  -> FunSets::contains
    -> FunSets::{closure}
      -> FunSets::contains
        -> FunSets::{closure}
        <- FunSets::{closure}
      <- FunSets::contains
      -> FunSets::contains
        -> FunSets::{closure}
        <- FunSets::{closure}
      <- FunSets::contains
    <- FunSets::{closure}
  <- FunSets::contains
  -> PHPUnit_Framework_Assert::assertFalse
    -> PHPUnit_Framework_Assert::isFalse
      -> {closure}
        -> main
        <- main
      <- {closure}
    <- PHPUnit_Framework_Assert::isFalse
    -> PHPUnit_Framework_Assert::assertThat
      -> PHPUnit_Framework_Constraint::count
      <- PHPUnit_Framework_Constraint::count
      -> PHPUnit_Framework_Constraint::evaluate
        -> PHPUnit_Framework_Constraint_IsFalse::matches
        <- PHPUnit_Framework_Constraint_IsFalse::matches
      <- PHPUnit_Framework_Constraint::evaluate
    <- PHPUnit_Framework_Assert::assertThat
  <- PHPUnit_Framework_Assert::assertFalse
<- FunSetsTest::testUnionContainsAllElements
...

Time: 1.85 seconds, Memory: 3.75Mb
OK (9 tests, 23 assertions)

The periods correspond to the successful tests before and after (and from) the test I was tracing.

You can see the function entry ("->") and return ("<-") points. Cross checking with the testUnionContainsAllElements() source code confirms the two singletonSet() calls, one union() call, two assertTrue() calls and finally an assertFalse() call. These assertions have a contains() call as a parameter, so contains() is called before the PHPUnit assertion functions are run. You can see contains() being called recursively, and how the closures are invoked.

If you want to focus on the application logic and suppress the PHPUnit function trace, you could turn off tracing when assertions are being checked by adding D clauses checking the entry and exit of assertFalse() and assertTrue().

But if you want to see all of PHPUnit's code flow, you can modify the functree.d code that sets and unsets self->follow, and instead change it to toggle the variable in request-startup and request-shutdown probes:

php$target:::request-startup
{
  self->follow = 1
}

php$target:::request-shutdown
{
  self->follow = 0
}

Be prepared for a large amount of output!

Wednesday Oct 02, 2013

DTrace PHP Using Oracle Linux 'playground' Pre-Built Packages

We've released DTrace-enabled PHP 5.5.4 RPMs to make testing DTrace on Oracle Linux easier. As a result, the manual PHP install steps listed in Using PHP DTrace on Oracle Linux can be skipped. There are updated Betas of the "UEK3" Linux Kernel 3.8.13-16 and the dtrace-utils tools available too. With these, you now can DTrace PHP applications under Apache or with php-fpm, as well as command line PHP scripts.

This post updates the install instructions, and show some of the probe changes in the latest PHP OCI8 2.0 extension.

Install Oracle Linux and the UEK3 Kernel

  1. Follow the steps to install Oracle Linux and the UEK3 Kernel given in the earlier blog post Using PHP DTrace on Oracle Linux

  2. Once the 3.8.13-16 Linux Kernel is installed and booted, enable user space tracing:

    # modprobe fasttrap
    # chmod 666 /dev/dtrace/helper
    

    Instead of the chmod, you could instead use an acl package rule to limit device access to a specific user.

Pre-installation for PHP

  1. Install the Oracle client libraries that PHP will use, oracle-instantclient12.1-basic-12.1.0.1.0-1.x86_64.rpm.

    Users with a ULN subscription can get this package from the "Oracle Software for Oracle Linux 6 (x86_64)" channel.

    If you don't have a ULN support subscription, and instead use public-yum.oracle.com, then manually download and install the free Instant Client RPM from OTN:

    # rpm -i oracle-instantclient12.1-basic-12.1.0.1.0-1.x86_64.rpm
    
  2. Add the "playground" channel via the ULN interface (for ULN subscribers), or for public-yum users, manually edit /etc/yum.repos.d/public-yum-ol6.repo and add:

    [public_ol6_playground_latest]
    name=Latest mainline stable kernel for Oracle Linux 6 ($basearch) - Unsupported
    baseurl=http://public-yum.oracle.com/repo/OracleLinux/OL6/playground/latest/$basearch/
    gpgkey=http://public-yum.oracle.com/RPM-GPG-KEY-oracle-ol6
    gpgcheck=1
    enabled=1
    

    Note "playground" is an unsupported channel and NOT for PRODUCTION use. It contains the DTrace-enabled PHP 5.5.4 RPMS.

Install PHP

  1. Install PHP and the PHP OCI8 extension:

    # yum install php55 php55-oci8-12cR1
    
    [. . .]
    
    ================================================================================
     Package            Arch     Version       Repository                      Size
    ================================================================================
    Installing:
     php55              x86_64   5.5.4-1.el6   public_ol6_playground_latest   1.4 M
     php55-oci8-12cR1   x86_64   5.5.4-3.el6   public_ol6_playground_latest   148 k
    Installing for dependencies:
     php55-cli          x86_64   5.5.4-1.el6   public_ol6_playground_latest   2.7 M
     php55-common       x86_64   5.5.4-1.el6   public_ol6_playground_latest   538 k
    
    Transaction Summary
    ================================================================================
    Install       4 Package(s)
    
    Total download size: 4.8 M
    Installed size: 17 M
    Is this ok [y/N]: y
    

    Other PHP packages are available too, but only core PHP and the PHP OCI8 extension have DTrace probes.

    Note that with the playground channel enabled, yum update will install a 3.11 kernel. If you reboot, make sure to select the 3.8.13 kernel for DTrace testing.

  2. Restart Apache:

    # service httpd restart

Use PHP and DTrace

  1. Create a PHP script, /var/www/html/oci8.php

    <?php
    
    error_reporting(E_ALL);
    ini_set('display_errors', 'On');
    
    function do_query($c, $sql)
    {
      $s = oci_parse($c, $sql);
      if (!$s)
        return;
      $r = oci_execute($s);
      if (!$r)
        return;
      echo "<table>\n";
      while (($row = oci_fetch_row($s)) != false) {
        echo "<tr>\n";
        foreach ($row as $item) {
          echo "<td>";
          echo $item!==null?htmlentities($item, ENT_QUOTES|ENT_SUBSTITUTE):"&nbsp;";
          echo "</td>\n";
        }
        echo "</tr>\n";
      }
      echo "</table>\n";
    }
    
    $c = oci_connect('hr', 'welcome', 'localhost/pdborcl');
    oci_set_client_identifier($c, "Chris");
    
    do_query($c, "select city from locations where rownum < 5 order by 1");
    
    ?>
    

    Change the connection credentials to those of your existing Oracle Database.

  2. Create a D script to trace the PHP OCI8 2.0.4 Probes, user_oci8.d:

    #!/usr/sbin/dtrace -Zqs
    
    php*:::oci8-connect-entry
    {
        printf("%lld: PHP connect-entry ", walltimestamp);
        printf("credentials=\"%s@", arg0 ? copyinstr(arg0) : "");
        printf("dbname=%s\" ", arg1 ? copyinstr(arg1) : "");
        printf("charset=\"%s\" ", arg2 ? copyinstr(arg2) : "");
        printf("session_mode=%ld ", (long)arg3);
        printf("persistent=%d ", (int)arg4);
        printf("exclusive=%d\n", (int)arg5);
    }
    
    php*:::oci8-connect-return
    {
        printf("%lld: PHP oci8-connect-return ", walltimestamp);
        printf("connection=0x%p\n", (void *)arg0);
    }
    
    php*:::oci8-connection-close
    {
        printf("%lld: PHP oci8-connect-close ", walltimestamp);
        printf("connection=0x%p\n", (void *)arg0);
    }
    
    php*:::oci8-error
    {
        printf("%lld: PHP oci8-error ", walltimestamp);
        printf("status=%d ", (int)arg0);
        printf("errcode=%ld\n", (long)arg1);
    }
    
    php*:::oci8-check-connection
    {
        printf("%lld: PHP oci8-check-connection ", walltimestamp);
        printf("connection=0x%p ", (void *)arg0);
        printf("client_id=\"%s\" ", arg1 ? copyinstr(arg1) : "");
        printf("is_open=%d ", arg2);
        printf("errcode=%ld ", (long)arg3);
        printf("server_status=%lu\n", (unsigned long)arg4);
    }
    
    php*:::oci8-sqltext
    {
        printf("%lld: PHP oci8-sqltext ", walltimestamp);
        printf("connection=0x%p ", (void *)arg0);
        printf("client_id=\"%s\" ", arg1 ? copyinstr(arg1) : "");
        printf("statement=0x%p ", (void *)arg2);
        printf("sql=\"%s\"\n", arg3 ? copyinstr(arg3) : "");
    }
    
    php*:::oci8-execute-mode
    {
        printf("%lld: PHP oci8-execute-mode ", walltimestamp);
        printf("connection=0x%p ", (void *)arg0);
        printf("client_id=\"%s\" ", arg1 ? copyinstr(arg1) : "");
        printf("statement=0x%p ", (void *)arg2);
        printf("mode=0x%x\n", arg3);
    }
    

    This prints each probe's arguments on a single, timestamp-prefixed line, which helps post-sorting the output in time order.

    The PHP OCI8 2.0.4 probe arguments have been enhanced from the PHP OCI8 2.0.2 probes described in Using PHP DTrace on Oracle Linux .

    If you want to trace the core PHP probes, they are described here.

  3. Start the D script:

    # ./user_oci8.d
    

    This will wait for probes to be fired. When you have finished testing, you can ^C this window.

  4. In a browser, load the PHP file: http://localhost/oci8.php. The web page will show query results. The probes that the D script used will fire and generate output (which I've manually wrapped to display cleanly in this blog post):

    # ./user_oci8.d
    1380749137317414976: PHP connect-entry
                         credentials="hr@localhost/pdborcl"
                         charset="" session_mode=0 persistent=0 exclusive=0
    1380749137354121877: PHP oci8-connect-return
                         connection=0x7f453c087b68
    1380749137354326373: PHP oci8-sqltext
                         connection=0x7f453c087b68 client_id="Chris"
                         statement=0x7f453c086f08
                         sql="select city from locations where rownum < 5 order by 1"
    1380749137354467732: PHP oci8-execute-mode
                         connection=0x7f453c087b68 client_id="Chris"
                         statement=0x7f453c086f08 mode=0x20
    1380749137355886348: PHP oci8-connect-close
                         connection=0x7f453c087b68
    ^C
    

    The client identifier ("Chris") is a way for the application to tell the database which web user is executing statements, since commonly the database user ("hr") is the same for all web users.

    In addition to all the database monitoring that you do for a given client identifier, with DTrace you can use the client identifier to trace a particular user on the PHP side of the DB connection. To do this, your D script might contain::

    #!/usr/sbin/dtrace -Zqs
    
    php*:::oci8-sqltext
    / (char *)arg1 == "Chris" /
    {
        printf("%lld: PHP oci8-sqltext ", walltimestamp);
        printf("connection=0x%p ", (void *)arg0);
        printf("client_id=\"%s\" ", arg1 ? copyinstr(arg1) : "");
        printf("statement=0x%p ", (void *)arg2);
        printf("sql=\"%s\"\n", arg3 ? copyinstr(arg3) : "");
    }
    
    php*:::oci8-execute-mode
    / (char *)arg1 == "Chris" /
    {
        printf("%lld: PHP oci8-execute-mode ", walltimestamp);
        printf("connection=0x%p ", (void *)arg0);
        printf("client_id=\"%s\" ", arg1 ? copyinstr(arg1) : "");
        printf("statement=0x%p ", (void *)arg2);
        printf("mode=0x%x\n", arg3);
    }
    

    The probes will only fire when the specified client identifier was "Chris". This will be useful for debugging on a busy production machine (once UEK3 becomes "production"). You can trace only the statements that your test user is running.

Summary

DTrace is an 'always available' tracing utility useful for identifying performance and behavior issues in applications on Solaris and Oracle Linux. The PHP core and PHP OCI8 extensions have user probes that can be traced to efficiently identify PHP scripting problems.

Monday Sep 09, 2013

Using PHP DTrace on Oracle Linux

This post shows PHP and DTrace "dynamic tracing" in action on Oracle Linux. It follows my previous post on recent PHP patches to stabilize DTrace support.

Install Oracle Linux and the UEK3 Kernel

  1. The starting point is to install Oracle Linux 6.4 from Oracle eDelivery. Wim Coekaerts blogged about the UEK3 release. I'm going to quote a paragraph from Wim here because it is fundamental to understanding Oracle Linux's direction:

    Oracle Linux is freely downloadable from http://edelivery.oracle.com/linux. Oracle Linux is free to use on as many systems as you want, is freely re-distributable without changing the CD/ISO content (so including our cute penguin), provides free security errata and bugfix errata updates. You only need to pay for a support subscription for those systems that you want/need support for, not for other systems. This allows our customers/users to run the exact same software on test and dev systems as well as production systems without having to maintain potentially two kinds of repositories. All systems can run the exact same software all the time.

  2. Once OL 6.4 is installed, add the Beta repo with:

    # cd /etc/yum.repos.d
    # mv public-yum-ol6.repo public-yum-ol6.repo.disabled
    # wget http://public-yum.oracle.com/beta/public-yum-ol6-beta.repo
    
  3. Enable the UEK3 Beta channel by editing public-yum-ol6-beta.repo and setting "enabled" to 1.

    enabled=1
  4. Install the UEK3 kernel, which supports DTrace:

    # yum update
  5. Install the DTrace utilities:

    # yum install dtrace-utils
  6. Reboot to the new UEK3 3.8.13 kernel

Install PHP

[Update: see DTrace PHP Using Oracle Linux 'playground' Pre-Built Packages for some pre-built PHP RPMs.]

  1. Download a PHP snapshot (or PHP 5.4.20 or PHP 5.5.4, when they become available) from snaps.php.net and extract it:

    $ tar -xJf php5.5-201309042230.tar.xz
    $ cd php5.5-201309042230
  2. Configure PHP:

    $ ./configure \
      --prefix=$HOME/p55 \
      --enable-dtrace \
      --disable-all --disable-cgi \
      --with-pear --enable-xml --enable-libxml --with-zlib

    This builds a minimal command line PHP with DTrace enabled. All unwanted extensions are disabled. You can include other extensions as needed. Currently PHP DTrace testing is limited to command-line use because a UEK3 DTrace fix for forked environments wasn't available at the time of the UEK3 Beta 1 release.

    The --prefix option puts the installation into a local directory, which makes it easy to see the files installed. It is easy to cleanup this directory when finished with the snapshot.

    The PEAR, XML and Zlib options allow the use of the 'pecl' command.

  3. Make the PHP binary and install it:

    $ make
    $ make install
  4. Copy php.ini-development to $HOME/p55/lib/php.ini and edit it to set the timezone, for example:

    date.timezone = America/Los_Angeles

Install PHP OCI8 for Oracle Database

To connect to Oracle Database, add PHP OCI8 as a "shared" extension:

  1. Download Oracle Instant Client "basic" and "devel" RPMs from ULN (for ULN subscribers) or OTN. You can use the 10g, 11g or 12c versions.

  2. Install Instant Client as root:

    # rpm -Uvh oracle-instantclient12.1-basic-12.1.0.1.0-1.x86_64.rpm
    # rmp -Uvh oracle-instantclient12.1-devel-12.1.0.1.0-1.x86_64.rpm
  3. As a normal user, set PATH so PHP is found:

    $ export PATH=$HOME/p55/bin:$PATH
  4. Set a PEAR proxy, if needed for access to http://pecl.php.net:

    $ pear config-set http_proxy http://myproxy.example.com:80/
  5. Set an environment variable PHP_DTRACE to enable DTrace, and install PHP OCI8:

    $ PHP_DTRACE=yes pecl install oci8-2.0.2

    The DTrace probes definitions used later in this article are based on PHP OCI8 2.0.2, so that explicit version is installed. If you install any future, later version review the probes and their arguments for differences. Note PHP OCI8 2.0 is in "development" status so changes are likely.

    When prompted for the ORACLE_HOME directory, hit return without entering text. The installation will autodetect the Instant Client RPMs. Configuration will continue and the output will contain something like:

    [ . . . ]
    checking for Oracle Database OCI8 support... yes, shared
    checking PHP version... 5.5.4, ok
    checking OCI8 DTrace support... yes
    [ . . . ]
    configure: WARNING: OCI8 extension: ORACLE_HOME is not set,
        looking for default Oracle Instant Client instead
    checking Oracle Instant Client directory...
        /usr/lib/oracle/12.1/client64/lib
    checking Oracle Instant Client SDK header directory...
       /usr/include/oracle/12.1/client64
    checking Oracle Instant Client library version compatibility... 12.1
    [ . . . ]
    
  6. Edit php.ini again and add PHP OCI8:

    extension=oci8.so
  7. Confirm the installation:

    $ php --ri oci8
    
    oci8
    
    OCI8 Support => enabled
    OCI8 DTrace Support => enabled
    OCI8 Version => 2.0.2-dev
    Revision => $Id: b30fb4bef45d9f5ce8a56b736f1546ea0cff08ef $
    Oracle Run-time Client Library Version => 12.1.0.1.0
    Oracle Compile-time Instant Client Version => 12.1
    
    Directive => Local Value => Master Value
    oci8.max_persistent => -1 => -1
    oci8.persistent_timeout => -1 => -1
    oci8.ping_interval => 60 => 60
    oci8.privileged_connect => Off => Off
    oci8.statement_cache_size => 20 => 20
    oci8.default_prefetch => 100 => 100
    oci8.old_oci_close_semantics => Off => Off
    oci8.connection_class => no value => no value
    oci8.events => Off => Off
    
    Statistics =>  
    Active Persistent Connections => 0
    Active Connections => 0

PHP OCI8 Installation Notes

For DTrace support, PHP OCI8 2.0 needs to be installed from PECL because PHP 5.4 and PHP 5.5 have PHP OCI8 1.4, which doesn't have DTrace probes. In future, when PHP 5.6 (or whatever comes after 5.5) is released, you will be able to configure a DTrace-enabled PHP OCI8 while building PHP.

You can, of course, install PHP OCI8 with Instant Client ZIP files, or simply use an existing ORACLE_HOME install.

You can DTrace-enable PHP OCI8 on a version of PHP that doesn't have DTrace available or configured. This includes older versions of PHP. You will be able to trace the PHP OCI8 probes but not any core PHP probes. Similarly you can install a DTrace-disabled PHP OCI8 on DTrace-enabled PHP.

If you install PHP OCI8 2.0 from PECL using 'phpize' and 'configure' (instead of 'pecl'), you will still need to set PHP_DTRACE=yes. This is because the --enable-dtrace option will be ignored by the limited 'configure' script of a PECL bundle.

The PHP OCI8 2.0 configuration script is suitable for "real" DTrace use but Linux SystemTap will not trace the extension.

Note that DTracing optimized binaries might give output that is not quite expected from code observation.

Verify the PHP DTrace Probes

  1. As root, enable DTrace and allow normal users to record trace information:

    # modprobe fasttrap
    # chmod 666 /dev/dtrace/helper

    Instead of the chmod, you could instead use an acl package rule to limit device access to a specific user.

  2. As a normal user, run php without any options. It will start and wait for input:

    $ php
  3. As root, list the DTrace probes that are available. Both PHP core and PHP OCI8 probes are listed:

    # dtrace -l -m php -m oci8.so
     4 php9559     php              dtrace_compile_file compile-file-entry
     5 php9559     php              dtrace_compile_file compile-file-return
     6 php9559     php                       zend_error error
     7 php9559     php ZEND_CATCH_SPEC_CONST_CV_HANDLER exception-caught
     8 php9559     php    zend_throw_exception_internal exception-thrown
     9 php9559     php                dtrace_execute_ex execute-entry
    10 php9559     php          dtrace_execute_internal execute-entry
    11 php9559     php                dtrace_execute_ex execute-return
    12 php9559     php          dtrace_execute_internal execute-return
    13 php9559     php                dtrace_execute_ex function-entry
    14 php9559     php                dtrace_execute_ex function-return
    15 php9559     php             php_request_shutdown request-shutdown
    16 php9559     php              php_request_startup request-startup
    17 php9559 oci8.so  php_oci_dtrace_check_connection oci8-check-connection
    18 php9559 oci8.so               php_oci_do_connect oci8-connect-entry
    19 php9559 oci8.so        php_oci_persistent_helper oci8-connect-expiry
    20 php9559 oci8.so            php_oci_do_connect_ex oci8-connect-lookup
    21 php9559 oci8.so php_oci_pconnection_list_np_dtor oci8-connect-p-dtor-close
    22 php9559 oci8.so php_oci_pconnection_list_np_dtor oci8-connect-p-dtor-release
    23 php9559 oci8.so               php_oci_do_connect oci8-connect-return
    24 php9559 oci8.so            php_oci_do_connect_ex oci8-connect-type
    25 php9559 oci8.so                    php_oci_error oci8-error
    26 php9559 oci8.so        php_oci_statement_execute oci8-execute-mode
    27 php9559 oci8.so             php_oci_create_spool oci8-sesspool-create
    28 php9559 oci8.so           php_oci_create_session oci8-sesspool-stats
    29 php9559 oci8.so           php_oci_create_session oci8-sesspool-type
    30 php9559 oci8.so         php_oci_statement_create oci8-sqltext
    

    The core PHP probes are documented here. ThePHP OCI8 probes are described below.

  4. In your user terminal, stop the php executable with Ctrl-C.

    $ php
    ^C
    $

PHP OCI8 2.0 DTrace Probe Overview

The static PHP OCI8 2.0 probes can be categorized as "user" probes and "maintainer" probes. The latter that are more useful for PHP OCI8 maintainers to verify functionality during development of the extension itself. All the probes return data in arguments.

User Probes are:

  • oci8-connect-entry - initiated by oci_connect(), oci_pconnect() and oci_new_connect(). Fires before database connection is established.
    • char *username - the connection username
    • char *dbname - the database connection string
    • char *charset - the character set specified
    • long session_mode - A binary "or" of OCI_SYSDBA (0x2), OCI_SYSOPER (0x4) and OCI_CRED_EXT (1<<31, or -2147483648 on the platform I was using). Set to 0 by default.
    • int persistent - set to 1 if oci_pconnect() was called, 0 otherwise
    • int exclusive - set to 1 if oci_new_connect() was called, 0 otherwise
  • oci8-connect-return - fires at the end of connection.
    • void *connection - the address of the connection structure
  • oci8-check-connection - initiated if an Oracle error might have caused the connection to become invalid
    • void *connection - the address of the connection structure
    • int is_open - will be 0 if the errcode or server_status indicate the connection is invalid and must be recreated.
    • long errcode - the Oracle error number
    • unsigned long server_status - an indicator from the Oracle library if the connection is considered invalid. If is_open is 0 because errcode indicated the connection was invalid, then server_status will be its default of 1.
  • oci8-sqltext - initiated when oci_parse() is executed
    • void *connection - the address of the connection structure
    • char *sql - text of the SQL statement executed
  • oci8-error - initiated if an Oracle error occurs
    • int status - the Oracle return status of the failing Oracle library call, such as -1 for Oracle's OCI_ERROR or 1 for Oracle's OCI_SUCCESS_WITH_INFO. See Oracle's oci.h for all definitions.
    • long errcode - the Oracle error number
  • oci8-execute-mode - indicates the commit state of an oci_execute() call
    • void *connection - the address of the connection structure
    • unsigned int mode - the mode passed to the Oracle library such as OCI_NO_AUTO_COMMIT (0x00), OCI_DESCRIBE_ONLY (0x10) or OCI_COMMIT_ON_SUCCESS (0x20)

Maintainer probes are below. Refer to the PHP OCI8 source code for the argument descriptions:

  • oci8-connect-p-dtor-close
    • void *connection
  • oci8-connect-p-dtor-release
    • void *connection
  • oci8-connect-lookup
    • void *connection
    • int is_stub
  • oci8-connect-expiry
    • void *connection
    • int is_stub
    • long idle_expiry
    • long timestamp
  • oci8-connect-type
    • int persistent
    • int exclusive
    • void *connection
    • long num_persistent
    • long num_connections
  • oci8-sesspool-create
    • void *session_pool
  • oci8-sesspool-stats
    • unsigned long free
    • unsigned long busy
    • unsigned long open
  • oci8-sesspool-type
    • int type
    • void *session_pool

The PHP OCI8 probes are highly likely to be extended prior to PHP OCI8 2.0 being marked "production". The PHP OCI8 documentation will be updated only at that time, but you can check the oci8_dtrace.d file in the PHP OCI8 source code to see the probe arguments for your version. (Update: The documentation is here).

The probes in PHP OCI8 2.0 replace PHP OCI8 1.4's use of oci_internal_debug() tracing. This function has become a no-op.

Using PHP OCI8 and DTrace

Follow these steps.

  1. Create a simple PHP file, oci8.php, to query the database:

    <?php
    
    error_reporting(0);
    ini_set('display_errors', 'Off');
    
    function do_query($c, $sql)
    {
        $s = oci_parse($c, $sql);
        if (!$s)
            return;
        $r = oci_execute($s);
        if (!$r)
            return;
        while (($row = oci_fetch_row($s)) != false) {
            foreach ($row as $item) {
                echo $item . " ";
            }
            echo "\n";
        }
    }
    
    $c = oci_new_connect('hr', 'welcome', 'localhost/pdborcl');
    
    do_query($c, "select city from locations where rownum < 5 order by 1");
    do_query($c, "select something from does_not_exist");
    
    ?>
  2. Create a D script, user_oci8.d, to probe the execution of oci8.php:

    #!/usr/sbin/dtrace -Zs
    
    php*:::oci8-connect-entry
    {
        printf("PHP connect-entry\n");
        printf("\t   username      %s\n", arg0 ? copyinstr(arg0) : "");
        printf("\t   dbname        %s\n", arg1 ? copyinstr(arg1) : "");
        printf("\t   charset       %s\n", arg2 ? copyinstr(arg2) : "");
        printf("\t   session_mode  %ld\n", (long)arg3);
        printf("\t   persistent    %d\n", (int)arg4);
        printf("\t   exclusive     %d\n", (int)arg5);
    }
    
    php*:::oci8-connect-return
    {
        printf("PHP oci8-connect-return\n");
        printf("\t   connection    0x%p\n", (void *)arg0);
    }
    
    php*:::oci8-connection-close
    {
        printf("PHP oci8-connect-close\n");
        printf("\t   connection    0x%p\n", (void *)arg0);
    }
    
    php*:::oci8-error
    {
        printf("PHP oci8-error\n");
        printf("\t   status        %d\n", (int)arg0);
        printf("\t   errcode       %ld\n", (long)arg1);
    }
    
    php*:::oci8-check-connection
    {
        printf("PHP oci8-check-connection\n");
        printf("\t   connection    0x%p\n", (void *)arg0);
        printf("\t   is_open       %d\n", arg1);
        printf("\t   errcode       %ld\n", (long)arg2);
        printf("\t   server_status %lu\n", (unsigned long)arg3);
    }
    
    php*:::oci8-sqltext
    {
        printf("PHP oci8-sqltext\n");
        printf("\t   connection    0x%p\n", (void *)arg0);
        printf("\t   sql           %s\n", arg0 ? copyinstr(arg1) : "");
    }
    
    php*:::oci8-execute-mode
    {
        printf("PHP oci8-execute-mode\n");
        printf("\t   connection    0x%p\n", (void *)arg0);
        printf("\t   mode          0x%x\n", arg1);
    }
    
  3. As root, start the D script. It will pause, waiting for probes to be fired:

    # chmod +x user_oci8.d
    # ./user_oci8.d

    (Later, this terminal can be Ctrl-C'd when you have finished experimenting with PHP)

  4. Run command-line PHP in another window. The output from the successful query is displayed:

    $ php oci8.php 
    Beijing 
    Bern 
    Bombay 
    Geneva 
    
  5. In the root terminal running the D script, the probes firing during execution of PHP will be displayed:

    # ./user_oci8.d
    dtrace: script 'user_oci8.d' matched 0 probes
    CPU  ID                    FUNCTION:NAME
    1    18 php_oci_do_connect:oci8-connect-entry PHP connect-entry
            username      hr
            dbname        localhost/pdborcl
            charset       
            session_mode  0
            persistent    0
            exclusive     0
    
    0    23 php_oci_do_connect:oci8-connect-return PHP oci8-connect-return
            connection    0x7f64e112cff0
    
    0    31 php_oci_statement_create:oci8-sqltext PHP oci8-sqltext
            connection    0x7f64e112cff0
            sql           select city from locations where rownum < 5 order by 1
    
    0    27 php_oci_statement_execute:oci8-execute-mode PHP oci8-execute-mode
            connection    0x7f64e112cff0
            mode          0x20
    
    0    31 php_oci_statement_create:oci8-sqltext PHP oci8-sqltext
            connection    0x7f64e112cff0
            sql           select something from does_not_exist
    
    0    27 php_oci_statement_execute:oci8-execute-mode PHP oci8-execute-mode
            connection    0x7f64e112cff0
            mode          0x20
    
    0    26 php_oci_error:oci8-error PHP oci8-error
            status        -1
            errcode       942
    
    0    17 php_oci_dtrace_check_connection:oci8-check-connection PHP oci8-check-connection
            connection    0x7f64e112cff0
            is_open       1
            errcode       942
            server_status 1
    
    0    25 php_oci_connection_close:oci8-connection-close PHP oci8-connect-close
             connection    0x7f64e112cff0

    (Adding "-q" to the /usr/sbin/dtrace arguments in user_oci8.d will suppress the CPU and ID details.)

    On multi-CPU machines the probe ordering might not appear sequential, depending on which CPU was processing the probes. Displaying probe timestamps will help reduce confusion, for example:

    php*:::oci8-connect-entry
    {
        printf("PHP connect-entry at %lld\n", walltimestamp);
    }

    From the user_oci8.d DTrace output, you can see

    • The connection being initiated (oci8-connect-entry). The user 'hr' connected to the 'localhost/pdborcl' database. It was an oci_connect() call because both 'exclusive' and 'persistent' were 0. No explicit character set was requested. The default session mode (the optional fifth parameter to oci_connect) was requested.

    • Two SQL statements being parsed (oci8-sqltext) and executed (oci-execute-mode) with mode 0x20 aka OCI_COMMIT_ON_SUCCESS.

    • An Oracle error ORA-942 "table or view does not exist" was generated (oci8-error)

    • The error causing the connection status to be verified (oci8-check-connection). The value of is_open is 1, indicating that the connection is OK.

    With this information you can trace problematic statement execution and connection issues.

Conclusion

This is just a morsel about using DTrace, which is a very powerful utility. Following on from the example above, you could integrate PHP OCI8 tracing with core PHP tracing. Bryan Cantrill posted some examples of core PHP tracing in DTrace and PHP, demonstrated (Note that blog platform upgrades have caused single backslashes to display as double backslashes in his post. Also you no longer need the separate PHP DTrace extension). To explore more DTrace power look on the web for example scripts. There are various blogs too.

Remember that the intent of DTrace is that its functionality is enabled all the time, suitable for development and ready for when you need it most: in production. The design of DTrace means that the probes have zero overhead when nothing is monitoring them.

Finally, as I write this article, I can already see how the PHP OCI8 probes can be enhanced (perhaps to display the connection client identifier to aid end-to-end tracing through the Oracle stack.) Oracle Linux support for DTrace should be improving all the time, too. The power of DTrace on Linux is growing and it's time to think about incorporating it into your application life cycle.

Updated 26 Sep 2013 to mention using an ACL rule for /dev/dtrace/helper

Wednesday Sep 04, 2013

DTrace with PHP Update

I've recently been working with the in-built DTrace code in PHP 5.4 and PHP 5.5, specifically stabilizing its configuration on Solaris and Oracle Linux.

DTrace is an always-available, low overhead, tracing framework that has just celebrated its 10th Birthday. DTrace support in PHP was originally via a separate PECL extension. In PHP 5.4 David Soria Parra (then at Sun) merged DTrace functionality to core PHP making it more accessible.

At the end of last year, I blogged about Adding DTrace Probes to PHP Extensions and how Linux's SystemTap could be used to trace the DTrace probe points. Since then, Oracle's Linux's DTrace project has been making great strides. The latest Oracle Linux UEK3 Beta kernel was just released. It comes with DTrace 0.4 and also supports "User-Level Statically Defined Tracing" (USDT) for the first time. This motivated me to make sure PHP DTrace worked well with "real" DTrace, not just with SystemTap's wrappers.

Some of the recent PHP DTrace changes were:

  • DTrace build script changes from PHP 5.5 were merged back to PHP 5.4 so both branches are now in sync.

  • A 'make install' recursive dependency issue that caused Zend/zend_dtrace.d to be deleted was fixed.

  • PHP DTrace configuration now uses the correct PIC or non-PIC objects. This also fixed building PHP when any extensions were built 'shared'.

  • A segmentation fault in the "error" probe was fixed.

  • PHP's OCI8 2.0 extension now builds correctly with "real" DTrace.

The changes were tested on Solaris and Oracle Linux. The core PHP changes should be available in the next monthly releases, PHP 5.4.20 and PHP 5.5.4. The PHP OCI8 2.0 changes are already available from PECL.

I'll cover more detail about using PHP and PHP OCI8 with DTrace on Oracle Linux in a later blog post, but the basic steps are:

  • Install the UEK3 kernel, currently in Beta from public-yum.oracle.com.

  • Install the dtrace-utils package with 'yum install dtrace-utils'

  • Download a PHP 5.4 or 5.5 snapshot from snaps.php.net (Or download PHP 5.4.20, PHP 5.5.4, or later, once they are available)

  • Configure PHP with the --enable-dtrace option

  • Load the DTrace module: modprobe fasttrap

  • Change the helper device to allow writing: chmod 666 /dev/dtrace/helper

  • Run a DTrace profiling script and your PHP application

Update: the detail is in a new blog post Using PHP DTrace on Oracle Linux

Thursday Dec 06, 2012

Adding DTrace Probes to PHP Extensions

The powerful DTrace tracing facility has some PHP-specific probes that can be enabled with --enable-dtrace.

DTrace for Linux is being created by Oracle and is currently in tech preview. Currently it doesn't support userspace tracing so, in the meantime, Systemtap can be used to monitor the probes implemented in PHP. This was recently outlined in David Soria Parra's post Probing PHP with Systemtap on Linux.

My post shows how DTrace probes can be added to PHP extensions and traced on Linux. I was using Oracle Linux 6.3.

Not all Linux kernels are built with Systemtap, since this can impact stability. Check whether your running kernel (or others installed) have Systemtap enabled, and reboot with such a kernel:

# grep CONFIG_UTRACE /boot/config-`uname -r`
# grep CONFIG_UTRACE /boot/config-*

When you install Systemtap itself, the package systemtap-sdt-devel is needed since it provides the sdt.h header file:

# yum install systemtap-sdt-devel

You can now install and build PHP as shown in David's article. Basically the build is with:

$ cd ~/php-src
$ ./configure --disable-all --enable-dtrace
$ make

(For me, running 'make' a second time failed with an error. The workaround is to do 'git checkout Zend/zend_dtrace.d' and then rerun 'make'. See PHP Bug 63704)

David's article shows how to trace the probes already implemented in PHP. You can also use Systemtap to trace things like userspace PHP function calls. For example, create test.php:

<?php

$c = oci_connect('hr', 'welcome', 'localhost/orcl');
$s = oci_parse($c, "select dbms_xmlgen.getxml('select * from dual') xml from dual");
$r = oci_execute($s);
$row = oci_fetch_array($s, OCI_NUM);
$x = $row[0]->load();
$row[0]->free();
echo $x;

?>

The normal output of this file is the XML form of Oracle's DUAL table:

$ ./sapi/cli/php ~/test.php
<?xml version="1.0"?>
<ROWSET>
 <ROW>
  <DUMMY>X</DUMMY>
 </ROW>
</ROWSET>

To trace the PHP function calls, create the tracing file functrace.stp:

probe process("sapi/cli/php").function("zif_*") {
    printf("Started function %s\n", probefunc());
}

probe process("sapi/cli/php").function("zif_*").return {
    printf("Ended function %s\n", probefunc());
}

This makes use of the way PHP userspace functions (not builtins) like oci_connect() map to C functions with a "zif_" prefix.

Login as root, and run System tap on the PHP script:

# cd ~cjones/php-src
# stap -c 'sapi/cli/php ~cjones/test.php' ~cjones/functrace.stp
Started function zif_oci_connect
Ended function zif_oci_connect
Started function zif_oci_parse
Ended function zif_oci_parse
Started function zif_oci_execute
Ended function zif_oci_execute
Started function zif_oci_fetch_array
Ended function zif_oci_fetch_array
Started function zif_oci_lob_load
<?xml version="1.0"?>
<ROWSET>
 <ROW>
  <DUMMY>X</DUMMY>
 </ROW>
</ROWSET>
Ended function zif_oci_lob_load
Started function zif_oci_free_descriptor
Ended function zif_oci_free_descriptor

Each call and return is logged. The Systemtap scripting language allows complex scripts to be built. There are many examples on the web.

To augment this generic capability and the PHP probes in PHP, other extensions can have probes too. Below are the steps I used to add probes to OCI8:

  1. I created a provider file ext/oci8/oci8_dtrace.d, enabling three probes. The first one will accept a parameter that runtime tracing can later display:

    provider php {
    	probe oci8__connect(char *username);
    	probe oci8__nls_start();
    	probe oci8__nls_done();
    };
    
  2. I updated ext/oci8/config.m4 with the PHP_INIT_DTRACE macro. The patch is at the end of config.m4. The macro takes the provider prototype file, a name of the header file that 'dtrace' will generate, and a list of sources files with probes. When --enable-dtrace is used during PHP configuration, then the outer $PHP_DTRACE check is true and my new probes will be enabled. I've chosen to define an OCI8 specific macro, HAVE_OCI8_DTRACE, which can be used in the OCI8 source code:

    diff --git a/ext/oci8/config.m4 b/ext/oci8/config.m4
    index 34ae76c..f3e583d 100644
    --- a/ext/oci8/config.m4
    +++ b/ext/oci8/config.m4
    @@ -341,4 +341,17 @@ if test "$PHP_OCI8" != "no"; then
         PHP_SUBST_OLD(OCI8_ORACLE_VERSION)
     
       fi
    +
    +  if test "$PHP_DTRACE" = "yes"; then
    +     AC_CHECK_HEADERS([sys/sdt.h], [
    +       PHP_INIT_DTRACE([ext/oci8/oci8_dtrace.d],
    +                       [ext/oci8/oci8_dtrace_gen.h],[ext/oci8/oci8.c])
    +         AC_DEFINE(HAVE_OCI8_DTRACE,1,
    +         [Whether to enable DTrace support for OCI8 ])
    +     ], [
    +       AC_MSG_ERROR(
    +         [Cannot find sys/sdt.h which is required for DTrace support])
    +     ])
    +   fi
    +
     fi
    
  3. In ext/oci8/oci8.c, I added the probes at, for this example, semi-arbitrary places:

    diff --git a/ext/oci8/oci8.c b/ext/oci8/oci8.c
    index e2241cf..ffa0168 100644
    --- a/ext/oci8/oci8.c
    +++ b/ext/oci8/oci8.c
    @@ -1811,6 +1811,12 @@ php_oci_connection *php_oci_do_connect_ex(char *username, int username_len, char
     		}
     	}
     
    +#ifdef HAVE_OCI8_DTRACE
    +    if (DTRACE_OCI8_CONNECT_ENABLED()) {
    +		DTRACE_OCI8_CONNECT(username);
    +	}
    +#endif
    +
     	/* Initialize global handles if they weren't initialized before */
     	if (OCI_G(env) == NULL) {
     		php_oci_init_global_handles(TSRMLS_C);
    @@ -1870,11 +1876,22 @@ php_oci_connection *php_oci_do_connect_ex(char *username, int username_len, char
     		size_t rsize = 0;
     		sword result;
     
    +#ifdef HAVE_OCI8_DTRACE
    +		if (DTRACE_OCI8_NLS_START_ENABLED()) {
    +			DTRACE_OCI8_NLS_START();
    +		}
    +#endif
     		PHP_OCI_CALL_RETURN(result, OCINlsEnvironmentVariableGet, (&charsetid_nls_lang, 0, OCI_NLS_CHARSET_ID, 0, &rsize));
     		if (result != OCI_SUCCESS) {
     			charsetid_nls_lang = 0;
     		}
     		smart_str_append_unsigned_ex(&hashed_details, charsetid_nls_lang, 0);
    +
    +#ifdef HAVE_OCI8_DTRACE
    +		if (DTRACE_OCI8_NLS_DONE_ENABLED()) {
    +			DTRACE_OCI8_NLS_DONE();
    +		}
    +#endif
     	}
     
     	timestamp = time(NULL);
    

    The oci_connect(), oci_pconnect() and oci_new_connect() calls all use php_oci_do_connect_ex() internally. The first probe simply records that the PHP application made a connection call. I already showed a way to do this without needing a probe, but adding a specific probe lets me record the username. The other two probes can be used to time how long the globalization initialization takes.

    The relationships between the oci8_dtrace.d names like oci8__connect, the probe guards like DTRACE_OCI8_CONNECT_ENABLED() and probe names like DTRACE_OCI8_CONNECT() are obvious after seeing the pattern of all three probes.

    I included the new header that will be automatically created by the dtrace tool when PHP is built. I did this in ext/oci8/php_oci8_int.h:

    diff --git a/ext/oci8/php_oci8_int.h b/ext/oci8/php_oci8_int.h
    index b0d6516..c81fc5a 100644
    --- a/ext/oci8/php_oci8_int.h
    +++ b/ext/oci8/php_oci8_int.h
    @@ -44,6 +44,10 @@
     #  endif
     # endif /* osf alpha */
     
    +#ifdef HAVE_OCI8_DTRACE
    +#include "oci8_dtrace_gen.h"
    +#endif
    +
     #if defined(min)
     #undef min
     #endif
    
  4. Now PHP can be rebuilt:

    $ cd ~/php-src
    $ rm configure && ./buildconf --force
    $ ./configure --disable-all --enable-dtrace \
                  --with-oci8=instantclient,/home/cjones/instantclient
    $ make
    

    If 'make' fails, do the 'git checkout Zend/zend_dtrace.d' trick I mentioned.

  5. The new probes can be seen by logging in as root and running:

    # stap -l 'process.provider("php").mark("oci8*")' -c 'sapi/cli/php -i'
    process("sapi/cli/php").provider("php").mark("oci8__connect")
    process("sapi/cli/php").provider("php").mark("oci8__nls_done")
    process("sapi/cli/php").provider("php").mark("oci8__nls_start")
    
  6. To test them out, create a new trace file, oci.stp:

    global numconnects;
    global start;
    global numcharlookups = 0;
    global tottime = 0;
    probe process.provider("php").mark("oci8-connect") {
        printf("Connected as %s\n", user_string($arg1));
        numconnects += 1;
    }
    probe process.provider("php").mark("oci8-nls_start") {
        start = gettimeofday_us();
        numcharlookups++;
    }
    probe process.provider("php").mark("oci8-nls_done") {
        tottime += gettimeofday_us() - start;
    }
    probe end {
        printf("Connects: %d, Charset lookups: %ld\n", numconnects, numcharlookups);
        printf("Total NLS charset initalization time: %ld usecs/connect\n", 
                            (numcharlookups > 0 ? tottime/numcharlookups : 0));
    }
    

    This calculates the average time that the NLS character set lookup takes. It also prints out the username of each connection, as an example of using parameters.

  7. Login as root and run Systemtap over the PHP script:

    # cd ~cjones/php-src
    # stap -c 'sapi/cli/php ~cjones/test.php' ~cjones/oci.stp
    Connected as cj
    <?xml version="1.0"?>
    <ROWSET>
     <ROW>
      <DUMMY>X</DUMMY>
     </ROW>
    </ROWSET>
    Connects: 1, Charset lookups: 1
    Total NLS charset initalization time: 164 usecs/connect
    

    This shows the time penalty of making OCI8 look up the default character set. This time would be zero if a character set had been passed as the fourth argument to oci_connect() in test.php.

Update: To use real (non-SystemTap) DTrace, the extension binary needs to be built slightly differently than shown above in step 2. Instead of modifying config.m4 to reuse PHP_INIT_DTRACE, an OCI8-specific variant of that macro is created. To see how this is done, look at the new OCI8_INIT_DTRACE macro definition and way it is used in PHP OCI8 2.0's ext/oci8/config.m4.

About

Tourists looking out over an Opal mine
I'm a Product Manager in Server Technologies, working on scripting languages and developer-access.
Email: christopher.jones@oracle.com
Twitter: http://twitter.com/ghrd
Book: Free PHP Oracle book
Download: PHP Linux RPMs with the OCI8 extension
Links: OTN PHP Developer Center

Search

Archives
« July 2014
SunMonTueWedThuFriSat
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
  
       
Today