Taking DTrace to the Next Level
14 Mar '09 - 09:05 by benrMy relationship with DTrace has been a rocky and strange sort of round trip. Like most folks, when it first arrived I built up a stash of one-liners, generally to expand upon output from vmstat and the like, such as to show execname for each page out or something. With Brendan Gregg's DTrace Toolkit I found several fun well written script and used them where appropriate. But frankly, serious DTrace use seemed to me to be akin to mdb use... most people should only bother scratching the surface, only kernel engineers need descend deeper. And, I'm not a kernel engineer.
All that changed when I needed answers to questions about emerging Solaris technologies (SMF, ZFS, COMSTAR, etc.) that were too new to get help from others. I'm not a kernel engineer... but DTrace can make me look like one by pairing up the source code with DTrace stack aggregations. A whole new world opened up and DTrace and I have been best friends since.
I've now moved out of the exploratory era and into the sustained monitoring era with DTrace. Not only do I want to run DTrace scripts interactively, not only do I want to run them periodically via some management agent, rather I want to run persistent traces.
Starting a DTrace session that just runs forever presents two initial problems:
- Is the tracing going to suck up resources or let buffers grow incrementally over days or weeks until the trace impacts the running environment?
- How do you collect the data? Pipe to file?
So far, in my experience, the first concern is put to rest. I've got several traces running that I keep a regular watch on for any growth... and day after day they remain unchanged, sturdy as a rock. This makes me happy. Please note that I am not using aggregations or the like.
Collecting the data in some rational way seemed more difficult. Sure, I could pipe the output somewhere or use the dtrace -o some/file but that just doesn't seem very flexible or professional to me. So I came up with a solution I like much better: Syslog!
Syslog is an amazing thing that is all too often under appreciated. Messages are sent to the daemon, which then routes them locally to a file or across the network to another syslog daemon which does the same. Combined with Splunk there isn't much that Syslog can't do. Syslog rules. To use syslog with DTrace there are two things to understand:
Firstly, using the Solaris logger command you can write messages to syslog from anywhere. This is super handy to embed in scripts, such as to signify that a backup is complete or some service is restarting or whatever. Here is an example:
root@quadra ~$ logger -p daemon.err 'Nightly Backup Failed!' root@quadra ~$ dmesg | tail -1 Mar 14 01:56:08 quadra root: [ID 702911 daemon.error] Nightly Backup Failed! root@quadra ~$ tail -1 /var/adm/messages Mar 14 01:56:08 quadra root: [ID 702911 daemon.error] Nightly Backup Failed!
Now, DTrace has the beautiful ability to run System Commands from within a clause. The trick is that this is considered a "destructive action", meaning it actually can modify the running state rather than simply observe it. When enabling a script to envoke destructive actions you should be very careful and trust no one, read the script before running! You can enable these actions on the command line with the -w option or by using the destructive pragma. The system() function in DTrace works much like printf() so variable substitution is easy.
So now lets look at a script that puts these two together. The script here enabled destructive actions so that we can use the system() function and calls out to logger to syslog output:
#!/usr/sbin/dtrace -s
/* Syslogging DTrace Script; benr. */
#pragma D option quiet
#pragma D option destructive
fbt::*_fsync:entry
/ execname != "logger" /
{
self->caller = execname;
self->start = timestamp;
}
fbt::*_fsync:return
/self->start/
{
this->end = timestamp;
this->duration = (this->end - self->start)/1000000;
system("/bin/logger -p local1.info %s by %s in %d ms", probefunc, self->caller, this->duration);
self->start = 0;
}
If we then setup syslog by adding some the following lines to /etc/syslog.conf and restarting syslog...
## Dtrace: local1.info /var/log/dtrace "/etc/syslog.conf" 62 lines, 1902 characters root@quadra ~$ touch /var/log/dtrace root@quadra ~$ svcadm restart system-log
Now we start the script and tail that new logfile:
root@quadra ~$ tail -f /var/log/dtrace Mar 14 02:20:35 quadra root: [ID 702911 local1.info] fop_fsync by ps in 0 ms Mar 14 02:20:35 quadra root: [ID 702911 local1.info] fop_fsync by auditd in 0 ms Mar 14 02:21:08 quadra last message repeated 7805 times Mar 14 02:21:08 quadra root: [ID 702911 local1.info] fop_fsync by nscd in 0 ms Mar 14 02:21:08 quadra last message repeated 3 times Mar 14 02:21:08 quadra root: [ID 702911 local1.info] fop_fsync by auditd in 0 ms Mar 14 02:21:17 quadra last message repeated 2282 times Mar 14 02:21:17 quadra root: [ID 702911 local1.info] fop_fsync by nscd in 0 ms Mar 14 02:21:17 quadra last message repeated 3 times Mar 14 02:21:18 quadra root: [ID 702911 local1.info] fop_fsync by auditd in 0 ms
If you need a refresher in syslog, please refer to my older post: Centralizing Syslog on Solaris.
Please understand! This is ONLY advisable for very low frequency probes! Running a system command from the script is not a lightweight thing and probes can fire a hell of a lot faster than shell commands can be evoked. Even the above example was a bad one, once I realized that auditing is a little overzealous. NEVER EVER EVER do this in a production environment without thoroughly testing it in your test environment. Moreover, if you misuse the system() function, don't blame DTrace!
Now, this isn't the only way or even the best way to syslog dtrace. Some other options exist such as piping to logger or even using an SMF wrapper to do so, such as Sam Falkner wrote some time ago. I implemented this way for two reasons: 1) because it works, and 2) because it demonstrates a way to extend your DTrace scripts in new ways using system() commands. My hope is that this excites in your mind some new and interesting uses.
It’s an interesting problem, and I think there are a few different ways of solving both (1) and (2). Your approach seems one that follows the ‘shrink to fit’ idea, it’s small, effective and does exactly what it needs to do and nothing more. I’ve started writing libdtrace(3) consumers for functional testing when prototyping code changes to the kernel. Basically an app that spawns worker threads and watches them with DTrace. You could potentially do something similar here, having a DTrace app that will trace what you want to trace and also periodically observe how that tracing is affecting the system, toning it down if negatively. You’d also be able to syslog without the destructive option, have better resource control of the tracing app, ... But clearly not a shrink to fit solution.
Rafael (URL) - 14 March '09 - 21:12
Thanks for this, Ben. How about some examples of monitors that you’ve found useful?Casey - 16 March '09 - 16:45
Thanks!generic (Email) (URL) - 12 April '09 - 16:17
It was a very nice idea! Just wanna say thank you for the information you have shared. Just continue writing this kind of post. I will be your loyal reader. Thanks again.Christian louboutin shoes (Email) (URL) - 27 October '09 - 03:24
Thank you very much!cheap links of london (Email) (URL) - 07 November '09 - 01:29
yeah ,i think sochristian louboutin (Email) (URL) - 15 November '09 - 11:36
Great post! Hope to be better. Better means more features.good post,I think so!
Thanks for your information, i have read it, very good！
Bing is a really overlord!! support Bing~~
This is great news. Best of luck for the future and keep up the good work.
tiffany and co (Email) (URL) - 19 November '09 - 01:22
goodchristian louboutin shoes (Email) (URL) - 05 December '09 - 07:56
Just one question: how to add your blog into my rrs reader, thanks so much.christian louboutin (Email) (URL) - 03 January '10 - 06:25
thank you for sharing it .and the article is very inspiring us to working hard in the company which sells christian louboutin shoes online.please come and see it.christian louboutin (Email) (URL) - 06 January '10 - 07:13
Do Mbt shoes really work ? go and try Mbt m walk or Mbt Chapa.[[http://www.discountmbt.com/]]
discount Mbt shoes (Email) (URL) - 08 January '10 - 03:52
very usefulchristian louboutin shoes (Email) (URL) - 08 January '10 - 06:50
Great Overview on Crossbow Ben! And thanks everyone fortrying it out. You can find more details relating to architecture
or building advanced virtual networks aka Virtual Wire at
Christian Louboutin Shoes will be the nice presents
christian louboutin (Email) (URL) - 09 January '10 - 12:03
discount mbt shoes can be found at our web,mbt chapa caviar black and mbt chapa sneakers are goog choices. [[http://www.mbt-lami.com]]mbt shoes (Email) (URL) - 12 January '10 - 08:09
gagalouboutin shoes (Email) (URL) - 13 January '10 - 03:46
Good post! Thanks you for your information! China Wholesale Wholesale China Wholesalers Wholesale Game Accessories Wholesale Iphone Accessories Video Game Accessories Wholesale Wholesale Wii Accessories Wholesale Xbox 360 Accessories Wholesale Xbox 360 Games Wholesale Video Games Cheap Video Games Cheap Ps3 Games Cheap Xbox 360 Games Wholesale Computers Wholesale Laptop Computers Wholesale Laptops Discount Computers Cheap Computers Wholesale Iphones Wholesale Iphone Wholesale Iphones 3g Hiphones Wholesale Hiphone Wholesale Hiphones Wholesale Nokia Wholesale Nokia 8800 Wholesale Nokia n97 wholesale blackberry wholesale blackberry phones wholesale blackberry 9700 wholesale blackberry 9600 wholesale blackberry 9500raging bull (Email) (URL) - 15 January '10 - 06:28
Good post! Thanks for your information! ed hardy ed hardy ed hardy clothing ed hardy clothing ed hardy swimwear ed hardy swimwear ed hardy jeans ed hardy jeans ed hardy hoodies ed hardy hoodies ed hardy shoes ed hardy shoes ed hardy uk ed hardy uk ed hardy bags ed hardy bags ed hardy shirts ed hardy shirts christian audigier christian audigier ed hardy mens ed hardy mens ed hardy womens ed hardy womens ed hardy kids ed hardy kids ed hardyed hardy (Email) (URL) - 15 January '10 - 07:35
[[http://www.buykamagra.com]] buy kamagra[[http://www.viagracialis.com]] viagra cialis
M65 Jacket (Email) (URL) - 21 January '10 - 02:06
good postabercrombie clothing (Email) (URL) - 22 January '10 - 08:30
Thanks for your sharing things! They’re gorgeous! We’re getting ready to launch our new online Christian Louboutin for smaller busted women, so I can definately appreciate all the hard work you’ve put into expanding your business! I know it’s quite a fete!!! Congratulations! Looking forward to seeing your shoes at more events and websites!christian louboutin (Email) (URL) - 25 January '10 - 12:45
Good post! Thanks for your information!As Seen On TV (Email) (URL) - 27 January '10 - 06:20
Everything will be all right,I am behind you.You ve got a point there.You said is right. I believe that to be completed.
iphone (Email) (URL) - 29 January '10 - 07:51
GHD styler iv is in season of GHD straighteners, you would like to try a piece of GHD pure.—- [[http://www.ghdhairirons.com]]bushworlda (Email) (URL) - 01 February '10 - 02:14
good post,I think so![url=[[http://www.mbttrainersshoes.com/]MBT]] trainers shoes[/url]
[url=[[http://www.mbttrainersshoes.com/]MBT]] Walking shoes[/url]
MBT trainers shoes (Email) (URL) - 01 February '10 - 06:31
nice post here， if you want to know more about best mbt shoes antd&ugg, just click [[http://www.bestmbtshoes.com]][[http://www.uggbootsroom.com]]
ugg (Email) (URL) - 06 February '10 - 03:22
Your article is very useful!