{"id":1705,"date":"2011-11-15T09:30:05","date_gmt":"2011-11-15T14:30:05","guid":{"rendered":"http:\/\/appcrawler.com\/wordpress\/?p=1705"},"modified":"2011-11-26T12:38:54","modified_gmt":"2011-11-26T17:38:54","slug":"using-awk-to-extract-bind-variable-values-from-a-trace-file","status":"publish","type":"post","link":"http:\/\/appcrawler.com\/wordpress\/2011\/11\/15\/using-awk-to-extract-bind-variable-values-from-a-trace-file\/","title":{"rendered":"Using awk to extract bind variable values from a trace file"},"content":{"rendered":"<p>While troubleshooting a high CPU utilization problem recently, I found that half the sessions using a given database service were using a high amount of CPU, while the other were using a normal amount.  Since I knew they were each running the exact same code, the logical conclusion was that the data differed.  I ended up enabling a 10046 event trace on each session, and reviewing the trace files to see if the data was different.  It turned out that it was, but it was a a painful process to go through each raw trace file and try to line up the bind variables to see if there were any repeating patterns, or differences.  As such, I wrote the following awk script to assist with this.<\/p>\n<p>All it does is take a SQL statement in which you are interested, and then searches each BIND section each time one is encountered for only that statement (or cursor#, more specifically).  It then totals the number of times a given variable was used.<\/p>\n<p>In this case, I wanted the SQL statement that began with &#8220;SELECT WORK_ID,&#8221;, and I was looking for bind variables for this statement that had the value 0362-4331.<\/p>\n<pre lang=\"awk\">\r\n#!\/bin\/awk -f\r\n\r\nBEGIN {\r\n  SQL=\"^SELECT WORK_ID,\"\r\n  BIND=\"0362-4331\"\r\n}\r\n\r\n{\r\n  if ($0 ~ \"^PARSING\") {\r\n    B=$4;\r\n    sub(\"#\",\"\",B);\r\n    getline;\r\n    if ($0 ~ SQL) {\r\n      C=B;\r\n    }\r\n  }\r\n  else if ($0 ~ \"BINDS #\" && $0 !~ \"BINDS #\"C) {\r\n    looking = 0;\r\n  }\r\n  else if (length(C) > 0 && $0 ~ \"BINDS #\"C) {\r\n    looking = 1;\r\n  }\r\n  else if ($0 ~ \"value=\" && looking == 1 && $0 ~ BIND) {\r\n    s[$0]+=1;\r\n  }\r\n}\r\n\r\nEND {\r\n  for (i in s) {\r\n    print i,s[i];\r\n  }\r\n}\r\n<\/pre>\n<p>You can also use what is below to extract the values and a count of each in a given BIND position for a given SQL statement.  All you need to do is pass the SQL statement for which to search, and the position in the bind list.  To get the &#8220;BIND&#8221; awk variable value, you will need to look at the raw tracefile.<\/p>\n<pre lang=\"awk\">\r\n#!\/bin\/awk -f\r\n#----------------------------------------------------------------------------------\r\n#Author:        Steve Howard\r\n#Date:          November 16, 2011\r\n#Purpose:       Extract bind variable values from a 10046 trace file. \r\n#----------------------------------------------------------------------------------\r\n\r\nBEGIN {\r\n  if (ARGC != 4) {\r\n    print \"Usage:\",ARGV[0],\" -f script_name tracefile_name \\\"query_for_which_to_search\\\" \\\"BindNumber\\\"\"\r\n    exit(1)\r\n  }\r\n  start = systime()\r\n  SQL=ARGV[2]\r\n  BIND=ARGV[3]\r\n  ARGC=2\r\n}\r\n\r\n{\r\n  if ($0 ~ \"^PARSING\") {\r\n    B=$4;\r\n    sub(\"#\",\"\",B);\r\n    getline;\r\n    if ($0 ~ SQL) {\r\n      C=B;\r\n    }\r\n    else if (C == B && $0 !~ SQL) {\r\n      C=-1;\r\n    }\r\n  }\r\n  else if ($0 ~ \"BINDS #\" && $0 !~ \"BINDS #\"C) {\r\n    looking = 0;\r\n  }\r\n  else if (length(C) > 0 && $0 ~ \"BINDS #\"C) {\r\n    looking = 1;\r\n  }\r\n  else if ($0 ~ BIND && looking == 1) {\r\n    looking=2;\r\n  }\r\n  else if ($0 ~ \"value=\" && looking == 2) {\r\n    sub(\"value=\",\"\",$0)\r\n    s[$0]++;\r\n    looking=0;\r\n  }\r\n}\r\n \r\nEND {\r\n  for (i in s) {\r\n    printf (\"%-50s %d\\n\", i,s[i])\r\n  }\r\n  printf(\"\\nProcessed %d lines in %d seconds.\\n\",NR,systime() - start)\r\n}\r\n<\/pre>\n<p>After making the script executable, you can call what is above with the command line shown below (changing the trace file, SQL for which to search, and Bind#, of course).<\/p>\n<pre lang=\"text\">\r\n.\/binds.awk OATEST_ora_17563710.trc \"select longname from javasnm\" \"Bind#0\"\r\n<\/pre>\n","protected":false},"excerpt":{"rendered":"<p>While troubleshooting a high CPU utilization problem recently, I found that half the sessions using a given database service were using a high amount of CPU, while the other were using a normal amount. Since I knew they were each&hellip;<\/p>\n<p class=\"more-link-p\"><a class=\"more-link\" href=\"http:\/\/appcrawler.com\/wordpress\/2011\/11\/15\/using-awk-to-extract-bind-variable-values-from-a-trace-file\/\">Read more &rarr;<\/a><\/p>\n","protected":false},"author":2,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"_mi_skip_tracking":false,"footnotes":""},"categories":[19,28,27,22],"tags":[],"_links":{"self":[{"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/posts\/1705"}],"collection":[{"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/users\/2"}],"replies":[{"embeddable":true,"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/comments?post=1705"}],"version-history":[{"count":24,"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/posts\/1705\/revisions"}],"predecessor-version":[{"id":1806,"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/posts\/1705\/revisions\/1806"}],"wp:attachment":[{"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/media?parent=1705"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/categories?post=1705"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/appcrawler.com\/wordpress\/wp-json\/wp\/v2\/tags?post=1705"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}