Using SMF to make DTrace a better printf replacement

When DTrace was introduced, life got much easier for kernel developers. For example, it became very easy to check if and when a certain function was being called. Before DTrace, if a debugger breakpoint was too heavy, we would often use printf()s. With DTrace, no more recompile/reboot!

Sure enough, one thing often discussed in the hallways was, "Yea! No more printf()s!" Yet I still find myself using printf()s. Not as often, certainly, and not in as many situations, but they haven't disappeared.

I think the reason I still use printf()s is that printf()s are "always on". With a printf() in the kernel, all output goes to /var/adm/messages. For example, if I'm writing bleeding edge code, I'd like to know if a certain routine fails. The routine might work at first, then fail a week later. With a printf(), I can always go back and look to see what happened. With DTrace, it's only there if I was running my script.

If only there were a way that I could use DTrace instead. If DTrace were always running on my development box, I wouldn't miss those unexpected things, and I wouldn't find myself wishing I had had a printf() at some point. If only there were some facility to start a D script, so that you wouldn't forget to launch it every day when you start working... Duh. Use SMF!

An SMF service to run a D script

You can find an SMF manifest for running a D script as a service here. You write a script, point this service at the script, enable via smf, and the script is always running! Output goes to /var/adm/messages via syslog.

Here's how to use it (you can also read these steps in the manifest itself):

  1. Download the file and save it in /var/svc/manifest/application/dtsyslog.xml
  2. # svccfg import /var/svc/manifest/application/dtsyslog.xml
  3. Write a script that you would like to run all the time. Put it somewhere, e.g. in /var/tmp.
  4. # svccfg
  5. svccfg> select dtsyslog
  6. svccfg> editprop
  7. Look for the line that says
    # setprop script/path = astring: /path/to/D/script
    Uncomment this line, and change "/path/to/D/script" to point to the path of your script.
  8. svccfg> quit
  9. #svcadm refresh dtsyslog
  10. #svcadm enable dtsyslog

Example

Let's try an example. Suppose I want to know when nfs4_setattr() is being called. Let's make a script:


#! /usr/sbin/dtrace -s

#pragma D option quiet

fbt::nfs4_setattr:entry
{
	printf("setattr called on %s\\n", stringof(args[0]->v_path));
}

Note the "#pragma" line: there is a way with the SMF properties that we could have passed a "-q" option to dtrace, but I prefer the pragma, as it makes the script more self contained. So, we store this file as /var/tmp/logger.d, and use svccfg to set the script/path property, and enable, and we're good to go!


burr/3/\* echo hello > foo
burr/4/\* chmod 666 foo 
burr/5/\* tail /var/adm/messages
Mar 13 14:02:50 burr pseudo: [ID 129642 kern.info] pseudo-device: fbt0
Mar 13 14:02:50 burr genunix: [ID 936769 kern.info] fbt0 is /pseudo/fbt@0
Mar 13 14:02:50 burr pseudo: [ID 129642 kern.info] pseudo-device: systrace0
Mar 13 14:02:50 burr genunix: [ID 936769 kern.info] systrace0 is /pseudo/systrace@0
Mar 13 14:02:50 burr pseudo: [ID 129642 kern.info] pseudo-device: profile0
Mar 13 14:02:50 burr genunix: [ID 936769 kern.info] profile0 is /pseudo/profile@0
Mar 13 14:02:50 burr pseudo: [ID 129642 kern.info] pseudo-device: lockstat0
Mar 13 14:02:50 burr genunix: [ID 936769 kern.info] lockstat0 is /pseudo/lockstat@0
Mar 13 14:21:38 burr dtsyslog: [ID 702911 daemon.notice] setattr called on /home/samf/foo
burr/6/\* 

Other Possibilities

You will likely want to edit your D script from time to time. When you do, just edit the script, and invoke "svcadm restart dtsyslog" to pick up the changes.

If you wish to have more than one script, you can easily create multiple instances of the dtsyslog service. Look at the man page for svccfg. Just edit the script/path property for each instance.

You can control the output via /etc/syslogd.conf. The messages are coming as daemon.notice by default, but you can also configure that via svccfg.

I hope you find this useful!

Comments:

That is very cool -- thanks!

Posted by Internet Dude. on March 13, 2008 at 08:41 AM MDT #

Post a Comment:
Comments are closed for this entry.
About

samf

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