Debugging AMP

In a previous post, I mentioned the availability of the dtrace extension for Cool Stack's PHP.  Using this extension and the Cool Stack MySQL, it is possible to analyze the performance of your application running on this stack. At JavaOne, we demoed this using the open source MediaWiki and SugarCRM applications.  dtrace is especially useful in analyzing complex multi-tier applications like AMP. Thanks to Angelo Rajadurai for the creation of the scripts that I describe below.

Analyzing PHP calls

So, let's look at a simple dtrace script that counts how many times a particular PHP function is called :

#!/usr/sbin/dtrace -Zqs

php\*:::function-entry
/arg0/
{
        @[copyinstr(arg0)]=count();
}

You can copy the above to a file named php.d and start it just before the operation you want to analyze. For example, if you want to see which php functions are called when you click on Edit in your mediawiki site, start the script, click the link, then terminate the script via \^C.

Analyzing MySQL calls

The following script will print the SQL command issued by the mysql process. Invoke the script with the pid of the mysqld process as an argument, just before you execute the operation you want to debug.

#!/usr/sbin/dtrace -qs

/\* This program prints the SQL commands executed by MySQL
 \* process. It takes the pid of the mysqld process as its
 \* only argument.
 \*
 \* This script observes the occurance of dispatch_command()
 \* function and prints the SQL statement (arg2). Before you
 \* use this D-script replace the mangled name below with the
 \* output run from the mysql bin directory :
 \*/usr/ccs/bin/nm mysqld | awk -F '{ print $NF; }' | grep dispatch_command
 \*
 \*/

pid$1::_Z16dispatch_command19enum_server_commandP3THDPcj:entry
{
        printf("%d::%s\\n",tid,copyinstr(arg2));
}

 

Tracing thru PHP & MySQL 

Finally, here's a script to trace through both the PHP and MySQL calls. The output is color-coded : blue for PHP functions and green for MySQL functions (admittedly there are many different ways to format the output and this one's a bit of a hack - but it works). This script should be passed the pid of the mysqld process as an argument. Note that this script assumes that both PHP and MySQL are running on the same system. If they are running on different systems, then you will have to run the individual scripts shown above on the different systems.

#!/usr/sbin/dtrace -ZqFs

/\* We use terminal escape sequence to change color
 \* PHP - Blue
 \* MYSQL - Green
 \*/
 
php\*:::function-entry
/arg0/
{
        printf("\\033[01;34m%s\\033[0m\\n",copyinstr(arg0));
}

php\*:::function-return
/arg0/
{
        printf("\\033[01;34m%s\\033[0m\\n",copyinstr(arg0));
}

pid$1::_Z16dispatch_command19enum_server_commandP3THDPcj:\*
{
        self->sql = copyinstr(arg2);
        printf("\\033[01;32m%s\\033[0m\\n",self->sql);
}

 

 

Comments:

hi Shanti

i'm useing the latest script in "Tracing thru PHP & MySQL"
traces are coming out for both php and mysql but after a while display is corrupted with exotic characters and i'm obliged to hard rest terminal window but i've lost a lot of info

did you experienced such issue ?

thks
Jean

Posted by jean jayet on March 28, 2008 at 01:57 AM PDT #

I don't know what you mean by 'after a while'. We didn't see any issues with it per se, since we did the tracing only when we clicked on something via the browser.

Posted by Shanti on March 28, 2008 at 03:16 AM PDT #

Post a Comment:
  • HTML Syntax: NOT allowed
About

I'm a Senior Staff Engineer in the Performance & Applications Engineering Group (PAE). This blog focuses on tips to build, configure, tune and measure performance of popular open source web applications on Solaris.

Search

Archives
« April 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
   
       
Today