Angelo's Soapbox

Monday Oct 26, 2009

A DTrace Quick Start Guide

Alta Elsta & I just completed the DTrace Quick Start Guide: Observing Native and Web Applications in Production mini-book. If you need a hardcopy let me know but if you are like me and would love to save a few trees you can click on the picture below to download the pdf version.

We talk about why DTrace is so different from any observation tools you may have seen. We cover basic DTrace concepts and some details on writing d-scripts. We also have a lot of sample scripts. Sections on using DTrace to observe MySQL and Drupal are included.

The examples from the book have also been added to a wiki page for easier copy & paste.

(click the image to open PDF)

Wednesday Jun 17, 2009

Diving into the Depths of Drupal with DTrace

I recently presented DTrace at Sun's CommunityONE event. My presentation was focused on observing drupal using DTrace. You can see a replay of the presentation here. You can get the presentation here as well.

If you are an AMP (Apache MySQL PHP) stack user on Solaris/OpenSolaris you can benefit from DTrace. Here is a D-Script that will print the load distribution on your system. Think of it as "AMP-top" if you may! This was tested on OpenSolaris 2009.06

#!/usr/sbin/dtrace -qs

BEGIN
{
	total=mysqlcnt=httpcnt=phpcnt=javacnt=ffxcnt=othercnt=0;
	printf("%10s %10s %10s %10s %10s %10s\n","% MYSQL","% APACHE","% FIREFOX","% PHP","% Java","% OTHER");
}

php*:::request-startup
{
	inphp[pid,tid]=1;
}

php*:::request-shutdown
{
	inphp[pid,tid]=0;
}

profile-1001
{
	total++;
	(execname=="mysqld")?mysqlcnt++:\
	     (execname=="httpd")?(inphp[pid,tid]==1?phpcnt++:httpcnt++):\
	     (execname=="java")?javacnt++:\
	     (execname=="firefox-bin")?ffxcnt++:othercnt++;
}

	

tick-30s
{
	printf("%10s %10s %10s %10s %10s %10s\n","% MYSQL","% APACHE","% FIREFOX","% PHP","% Java","% OTHER");
}

tick-2s
{
	printf("%10d %10d %10d %10d %10d %10d\n",mysqlcnt*100/total,\
              httpcnt*100/total,ffxcnt*100/total, phpcnt*100/total,\
              javacnt*100/total,othercnt*100/total);
	total=mysqlcnt=httpcnt=phpcnt=ffxcnt=javacnt=othercnt=0;

}

I will post other scripts soon. I plan to twitter these scripts as well. Follow me on twitter

Saturday Apr 25, 2009

DTrace presentation in JSconf 2009 Slides

I had an excellent time at JavaScript conference in DC this weekend. Some real smart guys in the room! Very impressive to see how far JavaScript has come! Interestingly many folks knew about DTrace! Here are my slides for the DTrace talk at JSconf 2009

Wednesday Apr 08, 2009

A drupal Aha moment, brought to you by Sun Unified Storage

Have you wondered what exactly an application is doing to your storage subsystem. Now you no longer have to wonder, you can find out exactly what its doing. Recently I was introduced to drupal and for DrupalCon I set up a BOF and demonstrated the use of Sun's Unified storage to observe Drupal. Yesterday I did a screen cast of the demo. You can see it @ "A drupal aha moment, brought to you by Sun's Unified Storage"

You can get one of the Unified storage systems to try out using Sun's Try & Buy Program. Or download a vmware appliance that simulates the Unified Storage.

Friday Oct 24, 2008

Optimizing the DTrace logger for MySQL queries

The Data Charmer Giuseppe Maxia did some quick tests on the DTrace script and was wondering if I could optimize it a little.

One issue with the old script is that it prints every SQL statement and this can be pretty expensive. This can be minimized by printing to a file. Here is a script that will do just that. The freopen() is not documented but it opens a file and sends all prints to the file. Giuseppe reports a 30% improvement in logging performance with this improved script.


#!/usr/sbin/dtrace -qws
BEGIN
{
	freopen("/tmp/sqls");
}

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

One more optimization that you can use with DTrace is the use of aggregates. Aggregates provides summary information. So this script will not provide you with the running log but if performance of the logger is important and you can live with the summary then this is the script for you.

#!/usr/sbin/dtrace -qs 
pid$1::*dispatch_command*:entry 
{ 
	@[copyinstr(arg2)]=count(); 
}

Strings in DTrace are 256 bytes by default. So these scripts will only show the first 256 chars of the SQL. If you need more then just change the default. Here is the script.

#!/usr/sbin/dtrace -qws
#pragma D option strsize=1024

BEGIN
{
	freopen("/tmp/sqls");
}

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

Finally, DTrace does the printing/aggregating asynchronously, so the performance of DTrace logging should be better than the typical database logging, at least on a system with enough free cycles.

PS: For those trying out the oracle SQL statements I found a better script than mine here

Friday Oct 17, 2008

Response: DTrace MySQL & SQL statement

A lot of comments on my last blog. Here is my response

How can I get more details for each SQL statement?
The second argument to dispatch_command is a pointer to the THD structure. It contains all sorts of information. You can dig for all the info you may ever need. Only issue is that we are now dealing with the internal structures and these may change for every release. So the script will not be portable. When I get a few minutes I'd blog a sample but your millage may vary.
A better way to get these structures is using the embedded MySQL DTrace probes. These will expose the info you need. For details on the embedded DTrace probes and example scripts on how to get these details see the discussion thread on OpenSolaris DTrace Discuss Finally the tid was printed to give you some amount of isolation based on connections. Not a great solution but good enough in most cases.

Why not just use MySQLProxy?
Because you need to turn it on and restart your mysql instance. With DTrace this process is truly dynamic. But as Kay Röpke explains, in MySQL 5.1 you can turn on query logging on the fly. DTrace of course can be used for many other things, not just query logging. Stay tuned for more to come in my blog

Can I do this for Oracle?
Of course you can. Its just another process as far as Solaris and DTrace are concerned. Here is a simple script that will print the SQL statements for Oracle. The function name is sqlcxt() the third argument is a pointer to the sqlexd structure. Search the web for the definition of the structure for your version of Oracle. Put it in a include file Oracle.h Then copy and run this script


#!/usr/sbin/dtrace -Cs
#include "oracle.h"
pid$1::sqlcxt:entry {

        this->s = (struct sqlexd *) copyin(arg2,sizeof(struct sqlexd));
        self->query = copyinstr((uintptr_t)this->s->stmt);
        printf("%s: %s\n",execname, self->query);
}

Why can't I do this in Linux? Is Sun making Linux the second choice
Kay already provided a very good response. I just want to point one more things. You can use Solaris Branded Zones to run DTrace on a Linux Application. See for details.
Not only are we not treating Linux as a second class citizen we have gone out of the way to help out our friends in the Linux community even though they have been reluctant in getting DTrace ported.

Thursday Oct 16, 2008

Using DTrace to observe the SQL statements on a live running MySQL database

DTrace allows you to instrument any live running application in production without the need of extra coding, application recompile or even an application restart. All you need is that the application is running on an OS that supports DTrace. Today Solaris, OpenSolaris, OS X and FreeBSD are a few that have DTrace built in.

For example here is a D-script that instrument MySQL to observe the SQL statements that is being executed in production. Just a 3 line script like this can be extremely useful to observe a live MySQL database


#!/usr/sbin/dtrace -qs
pid$1::*dispatch_command*:entry
{
    printf("%d::%s\n",tid,copyinstr(arg2));
}
You need to pass the pid of the mysql process as the first argument to this script.

Here is a sample output from the script. We are observing the SQL statements that are executed to bring up the SugarCRM login screen.


# pgrep mysql
418
254
# ./mysql.d 418
11::sugarcrm
11::SET CHARACTER SET utf8
11::SET NAMES 'utf8'
11::SELECT id, name, symbol, conversion_rate FROM currencies WHERE
status = 'Active' and deleted = 0
11::SELECT category, name, value FROM config
11::SELECT id FROM outbound_email WHERE type = 'system'
11::SELECT * FROM outbound_email WHERE id =
'592d612d-3fd2-fa02-f067-48d0467e2da0'
11::
12::sugarcrm
12::SET CHARACTER SET utf8
12::SET NAMES 'utf8'
12::SELECT id, name, symbol, conversion_rate FROM currencies WHERE
status = 'Active' and deleted = 0
12::SELECT category, name, value FROM config
12::SELECT id FROM outbound_email WHERE type = 'system'
12::SELECT * FROM outbound_email WHERE id =
'592d612d-3fd2-fa02-f067-48d0467e2da0'
12::SELECT acl_actions .*, acl_roles_actions.access_override
                   FROM acl_actions
                   LEFT JOIN acl_roles_users ON
acl_roles_users.user_id = '' AND  acl_roles_users.deleted = 0
                   LEFT JOIN acl_roles_actions
12::SELECT count(*) as the_count FROM config WHERE category='info' AND
name='sugar_version' AND value = '5.1.0'
12::SELECT category, name, value FROM config
12::SELECT id FROM outbound_email WHERE type = 'system'
12::SELECT * FROM outbound_email WHERE id =
'592d612d-3fd2-fa02-f067-48d0467e2da0'
12::INSERT INTO tracker
(monitor_id,module_name,date_modified,action,session_id ) VALUES (
'97e1d39b-c036-1e1f-bf2f-48f763a6045c','Users','2008-10-16
15:53:13','login','8fbb9c1a0ac421964fa4a45db4086a46')
12::SELECT user_name FROM users WHERE id='1'

Please note you do not need anything special from MySQL. This will run with any plain vanilla mysql instance with no restart or special flags

How does the script work
We are using the pid provider in DTrace to instrument the dispatch_command method of the live running MySQL instance. This is the method that is called when any SQL statement is executed. The third argument for this method is a string that contains the SQL statement. We are just printing the third argument in the D-script

As always let me know if you need more details

Friday Oct 03, 2008

Using DTrace to change OS version

You may have heard about Solaris' legendary binary compatibility guarantee. Basically we guarantee that any binary that runs on Solaris 7,8 & 9 will run unmodified on Solaris 10.

In spite of this excellent binary compatability we have seen some of our partner's Solaris 9 apps fail to install on Solaris 10 because the installer thinks that "10" is less than "9" (using ASCII compare). I figured that we can use DTrace to fix the version number to allow the installer to work.

So I wrote a simple script that will fix the version of Solaris. Here is the script

#!/usr/sbin/dtrace -qws
	
syscall::uname:entry
/progenyof($1)/
{
	self->addr = arg0;
}

syscall::uname:return
/progenyof($1)/
{
	copyoutstr("5.9", self->addr+(257*2), 257);
}

This script takes the pid of the shell that runs the installer. (echo $$ on the terminal to get the pid) While this script is running, uname -a on that shell will return 5.9 as a the Solaris version.

Wednesday Sep 17, 2008

Web 2.0 Expo NY

Hello from the demo floor of the Web 2.0 Expo in New York

It has been a lot of fun getting to meet with a lot of Web 2.0 companies. It blows my mind to just see how much this market has matured.

If you are at the Web 2.0 Expo NY please stop at the Sun booth. Tell them Angelo sent you and get a nice OpenSolaris cap or T-shirt.

Come by my BOF on Observing the Web 2.0 Application in Production September 9/18/08 Thursday 7 PM at "Boardroom C-Hudson Hotel". We will have an interactive session. So would love to hear your ideas and feeback.

Also check out Project Kenai and Zembly at the Sun booth.

If you are a startup. The SSE program is just the thing for you. See Sun Startup Essentials

Come by booth 1701

Tuesday Jul 15, 2008

DTrace screencast

Its been a while since I blogged here. So wanted to do blog some good content. I work in the Open Source team at Sun and I'm focusing on Emerging Markets. Its a pretty exciting work and I'm enjoying very bit of it.

Recently I came across an open source project called the "Jing Project". Jing makes creating screen casts a breeze. I've been playing with it and created a few screen casts to demonstrate DTrace. If you have not seen DTrace in action here is your chance.

To make it easy for download and viewing the screen cast has been split into 5 parts. Easy on the bandwidth and easy on the eyes. So without much more ado here are the screen casts. Enjoy and provide feedback.

DTrace screen casts
Name Description
Introductory Presentation 01-Intro.swf
Observing System calls 02-demo-syscall1.swf
System call arguments 03-demo-syscall2.swf
Library calls and arguments 04-demo-libc.swf
DTrace and JavaScript 05-demo-javascript.swf


You may need a flash player to view these screen casts.

I plan to do DTrace tutorials in the next series of screen casts. Enjoy and don't forget to provide feedback.

Tuesday May 22, 2007

DTrace meets the AMP (Apache MySQL PHP) stack

During JavaOne this year Rags and I did a hands on lab on DTrace. The topic was "Using DTrace on Java and other Web 2.0 Languages in Solaris". Due to some unforeseen reason the lab was scheduled from 8:45 PM to 10:45 PM (Yes PM) and that to on the day of the big party at JavaOne. So I was expecting to be speaking to an empty room but lo and behold we had close to 100 engineers ( a few pretty drunk) and most stayed until the finished the lab.It was pretty heartening and was worth all the efforts that went into it.

One of the highlights of the lab was a script that we developed. It lists the JavaScript & PHP function entry and MySQL SQLs that happen live system. You need the following prerequisite for the script to be fully functional.

Here is the script. It takes one argument - the pid of the mysqld process in your system.

#!/usr/sbin/dtrace -ZqFs
/* We use terminal escape sequence to change color
 * Javascript - Red
 * PHP - Blue
 * MYSQL - Green
 */
 
trace_mozilla*:::js_function-entry
{
        printf("\033[01;31m%s\033[0m\n",copyinstr(arg2));
}

trace_mozilla*:::js_function-return
{
        printf("\033[01;31m%s\033[0m\n",copyinstr(arg2));
}

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);
}

 You will see a nice color coded output. Javascript calls in Red, PHP in Blue and MySQL in green.

In subsequent blogs I try and go through the process of developing this code. Meanwhile enjoy Solaris DTrace

Monday Apr 02, 2007

DTrace, April Fools and Solaris 10 Binary Compatability.

Its been a while since I blogged. Its definitely not for lack of content but lack of the discipline to sit down and "just do it". Well its about time.

Its rare to get an opportunity to talk about such varied topics such as Solaris Binary Application Guarantee , DTrace and April fools all in one blog. So it would be a shame if I let it pass.

I work in the ISV engineering team in Sun and as you may have guessed we work with Sun's software partners - ISVs (Independent Software Vendors). One of the things that I noticed was that some of our partner applications would fail to install on Solaris 10. This was frustrating to me as the problem was not with the partner application but their installer. Typically the installer fails when it find that the Solaris version is 10. If only I could get past the installer issue I'd have a an application that works perfectly fine.

So I wrote a simple D-script to fool the installer into thinking it is a Solaris 9 machine. You can try this the next time you find yourself struggling with an program that insists on a older version of Solaris.


#!/usr/sbin/dtrace -qs

#pragma D option destructive

BEGIN
{
        printf("Changing output of uname for pid %d and its descendants...\n",$1);
}

syscall::uname:entry 
/progenyof($1)/
{
        self->addr = arg0; 
}

syscall::uname:return
/progenyof($1)/
{
        copyoutstr("5.9", self->addr+(257*2), 257);
}


This script expects the pid of a shell as its only argument and it will change the uname version to 5.9 for this shell and all its descendants and as with all D-scripts once you stop this script (with a ^c) everything would be back as it was before.

Enjoy!

Wednesday Nov 15, 2006

Solaris presentation at Colby College

Yesterday I had an excellent opportunity to present DTrace and ZFS at Colby College . There were folks from the CS department and IT dept. It was very heartening to see the interest in Solaris. The lecture was part of their CS Colloquium.

Presenting to CS students is always a challange. They seem to come up with a unique set of questions. The student generally are not "corrupted" by the rigors of  IT world and they tend to ask more "why" rather than "how" questions.

After a pretty detailed presentation my resources slide had just one entry http://opensolaris.org/  Everything you need to know about DTrace and ZFS is in OpenSolaris. If you've not been there at OpenSolaris recently check it out.

Tuesday Aug 01, 2006

DTrace could have saved the Vista Voice Recognition Demo

Looks like Microsoft has an unfair share of unfavorable visits from the demo gods. For example just last week a demo of the Voice recognition feature of Vista went horribly bad and a video of the failed demo was all over the net. Google Video , Slash Dot and YouTube all have helped to spread the video around. I just came across Microsoft's Larry Osterman's blog. He claims responsibility for the snafu and explains the details of why this went wrong. While there is a lot of good info in the blog that may be of interest to a analog audio engineer the following line in his blog caught my attention. The annoying thing about it was that the bug wasn't reproducible - every time he stepped through the code in the debugger, it worked perfectly, but it kept failing when run without any traces. I'm sure we all have faced similar problems. They seem to go away as soon as you attach a debugger to it or even add some custom instrumentation (printf) to the application. In this case the problem was occurring if they had a positive feedback loop and the problem was very time sensitive. Solaris 10 Dynamic Tracing or DTrace in short is absolutely the best tool in the market today to diagnose such problems. It frees you from having to do custom instrumentation and helps you diagnose problems in a live production setting without incurring the overhead of traditional debuggers. Now if only Vista had DTrace! Larry could have diagnosed the problem without having to incur the big cost of a stepping through the debugger. To learn more about DTrace see Solaris 10 Dynamic Tracing Users Guide DTrace Webcast - (shameless self promotion) Brendan Greggs DTrace Toolkit Tags: ,

Tuesday May 02, 2006

10000 DTrace webcast downloads!

Time for some gloating about the popularity of DTrace and a bit of joy about a personal milestone. For most of last year I've been evangelizing the capabilities of Solaris 10 Dynamic tracing technology DTrace, among Sun's partner community. Most of the effort has gone into in person presentations, which has been by far the most rewarding. Just to see the amazement on peoples faces when the realize the power of the tool is worth every second of effort that goes into these presentations. But with three kids at home, traveling can be very disruptive. So I've been trying to use technology to advance the cause. We did webcasts and Hands on Lab and gave the presentation material to other able presenters. The webcasts and Hands on Labs are freely available on the net. Last week we reached an exciting milestone. Over 10,000 (yes 4 zeros) people have downloaded and viewed the webcast. If you have viewed the Webcast I'd like to hear from you.Email me at angelo dot rajadurai at sun dot com. Let me know if you liked it. What types of other material would you like to see on DTrace? If you are interested in DTrace and have been looking to learn about its capabilities here are a few resources for you. DTrace webcast Hands on Labs DTrace BigAdmin site DTrace community on OpenSolaris.org Brendan Gregg's DTrace tools Solaris 10 Dynamic Tracing (DTrace) guide

Technorati tag:



  Free Tech Webinars  

Archives
Links
Referrers