Activate your free membership today | Log-in

Wednesday, July 25th, 2007

End-to-End Tracing of Ajax/Java Applications Using DTrace

Category: Utility

<p>We posted about using DTrace to profile Firefox in the past, and today Amit Hurvitz published a piece on Ajax, DTrace and Where They Meet.

The article walks you through setting up dtrace on an an Ajax tracing example and then goes into detail on tracing Ajax and Java call flow where they are tracing the call flow of the JavaScript functions and the Java servlet methods, which responds to the Ajax calls using the script:

PLAIN TEXT
JAVASCRIPT:
  1.  
  2. #!/usr/sbin/dtrace -Zs
  3.  
  4. #pragma D option quiet
  5. #pragma D option switchrate=10
  6.  
  7. dtrace:::BEGIN
  8. {
  9.         jsIndent = 0;
  10.         jsFile = "ajax-validation";
  11.         javaMethodBoundary= "doGet";
  12.         startTimestamp = timestamp;
  13. }
  14.  
  15. *mozilla$1:::js_function-entry
  16. /basename(copyinstr(arg0)) == jsFile/
  17. {
  18.         jsIndent += 2;
  19.         printf("%*s -> %s:%s (JavaScript)(elapsed ms: %d)n", jsIndent, "",
  20.             jsFile, copyinstr(arg2), (timestamp - startTimestamp) / 1000);
  21. }
  22.  
  23. *mozilla$1:::js_function-return
  24. /basename(copyinstr(arg0)) == jsFile/
  25. {
  26.         printf("%*s <- %s:%s (JavaScript)(elapsed ms: %d)n", jsIndent, "",
  27.             jsFile, copyinstr(arg2), (timestamp - startTimestamp) / 1000);
  28.         jsIndent -= 2;
  29. }
  30.  
  31.  
  32. hotspot$2:::method-entry
  33. {
  34.         self->strPtr = (char *)copyin(arg1, args[2]+1);
  35.         self->strPtr[(int)args[2]] = '';
  36.         self->classStr = (string)self->strPtr;
  37.         self->strPtr = (char *)copyin(arg3, (int)args[4]+1);
  38.         self->strPtr[(int)args[4]] = '';
  39.         self->methodStr = (string)self->strPtr;
  40. }
  41.  
  42. hotspot$2:::method-entry
  43. /javaMethodBoundary == self->methodStr/
  44. {
  45.         self->interested = 1;
  46.         self->indent = 0;
  47. }
  48.  
  49. hotspot$2:::method-entry
  50. /self->interested/
  51. {
  52.         self->indent += 2;
  53.         printf("%*s -> %s:%s (Java)(elapsed ms: %d)n", self->indent, "",
  54.             self->classStr, self->methodStr, (timestamp - startTimestamp) / 1000);
  55. }
  56.  
  57. hotspot$2:::method-return
  58. {
  59.         self->strPtr = (char *)copyin(arg1, args[2]+1);
  60.         self->strPtr[(int)args[2]] = '';
  61.         self->classStr = (string)self->strPtr;
  62.         self->strPtr = (char *)copyin(arg3, (int)args[4]+1);
  63.         self->strPtr[(int)args[4]] = '';
  64.         self->methodStr = (string)self->strPtr;
  65. }
  66.  
  67. hotspot$2:::method-return
  68. /self->interested/
  69. {
  70.         printf("%*s <- %s:%s (Java)(elapsed ms: %d)n", self->indent, "",
  71.             self->classStr, self->methodStr, (timestamp - startTimestamp) / 1000);
  72.         self->indent -= 2;
  73. }
  74.  
  75. hotspot$2:::method-return
  76. /javaMethodBoundary == self->methodStr/
  77. {
  78.         self->interested = 0;
  79.         /* exit(0); */
  80. }
  81.  

It then continues to show timings of methods and such. This may not be the simplest solution for debugging, but at least you can get inside the black box when you need too.

Related Content:

Posted by Dion Almaer at 12:14 pm
Comment here

+----
1.3 rating from 195 votes

Comments Here »

Comments feed TrackBack URI

Leave a comment

You must be logged in to post a comment.