| 1 | /* Copyright (c) 2007, 2012, Oracle and/or its affiliates. |
| 2 | Copyright (c) 2008, 2012, Monty Program Ab |
| 3 | |
| 4 | This program is free software; you can redistribute it and/or modify |
| 5 | it under the terms of the GNU General Public License as published by |
| 6 | the Free Software Foundation; version 2 of the License. |
| 7 | |
| 8 | This program is distributed in the hope that it will be useful, |
| 9 | but WITHOUT ANY WARRANTY; without even the implied warranty of |
| 10 | MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the |
| 11 | GNU General Public License for more details. |
| 12 | |
| 13 | You should have received a copy of the GNU General Public License |
| 14 | along with this program; if not, write to the Free Software |
| 15 | Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA */ |
| 16 | |
| 17 | |
| 18 | /** |
| 19 | @file |
| 20 | |
| 21 | Implement query profiling as as list of metaphorical fences, with one fence |
| 22 | per query, and each fencepost a change of thd->proc_info state (with a |
| 23 | snapshot of system statistics). When asked, we can then iterate over the |
| 24 | fenceposts and calculate the distance between them, to inform the user what |
| 25 | happened during a particular query or thd->proc_info state. |
| 26 | |
| 27 | User variables that inform profiling behavior: |
| 28 | - "profiling", boolean, session only, "Are queries profiled?" |
| 29 | - "profiling_history_size", integer, session + global, "Num queries stored?" |
| 30 | */ |
| 31 | |
| 32 | #include "mariadb.h" |
| 33 | #include "sql_priv.h" |
| 34 | #include "sql_profile.h" |
| 35 | #include "sql_show.h" // schema_table_store_record |
| 36 | #include "sql_class.h" // THD |
| 37 | |
| 38 | #ifdef _WIN32 |
| 39 | #pragma comment(lib,"psapi.lib") |
| 40 | #endif |
| 41 | |
| 42 | #define TIME_FLOAT_DIGITS 9 |
| 43 | /** two vals encoded: (len*100)+dec */ |
| 44 | #define TIME_I_S_DECIMAL_SIZE (TIME_FLOAT_DIGITS*100)+(TIME_FLOAT_DIGITS-3) |
| 45 | |
| 46 | #define MAX_QUERY_LENGTH 300 |
| 47 | #define MAX_QUERY_HISTORY 101 |
| 48 | |
| 49 | /** |
| 50 | Connects Information_Schema and Profiling. |
| 51 | */ |
| 52 | int fill_query_profile_statistics_info(THD *thd, TABLE_LIST *tables, |
| 53 | Item *cond) |
| 54 | { |
| 55 | #if defined(ENABLED_PROFILING) |
| 56 | return(thd->profiling.fill_statistics_info(thd, tables, cond)); |
| 57 | #else |
| 58 | my_error(ER_FEATURE_DISABLED, MYF(0), "SHOW PROFILE" , "enable-profiling" ); |
| 59 | return(1); |
| 60 | #endif |
| 61 | } |
| 62 | |
| 63 | ST_FIELD_INFO query_profile_statistics_info[]= |
| 64 | { |
| 65 | /* name, length, type, value, maybe_null, old_name, open_method */ |
| 66 | {"QUERY_ID" , 20, MYSQL_TYPE_LONG, 0, false, "Query_id" , SKIP_OPEN_TABLE}, |
| 67 | {"SEQ" , 20, MYSQL_TYPE_LONG, 0, false, "Seq" , SKIP_OPEN_TABLE}, |
| 68 | {"STATE" , 30, MYSQL_TYPE_STRING, 0, false, "Status" , SKIP_OPEN_TABLE}, |
| 69 | {"DURATION" , TIME_I_S_DECIMAL_SIZE, MYSQL_TYPE_DECIMAL, 0, false, "Duration" , SKIP_OPEN_TABLE}, |
| 70 | {"CPU_USER" , TIME_I_S_DECIMAL_SIZE, MYSQL_TYPE_DECIMAL, 0, true, "CPU_user" , SKIP_OPEN_TABLE}, |
| 71 | {"CPU_SYSTEM" , TIME_I_S_DECIMAL_SIZE, MYSQL_TYPE_DECIMAL, 0, true, "CPU_system" , SKIP_OPEN_TABLE}, |
| 72 | {"CONTEXT_VOLUNTARY" , 20, MYSQL_TYPE_LONG, 0, true, "Context_voluntary" , SKIP_OPEN_TABLE}, |
| 73 | {"CONTEXT_INVOLUNTARY" , 20, MYSQL_TYPE_LONG, 0, true, "Context_involuntary" , SKIP_OPEN_TABLE}, |
| 74 | {"BLOCK_OPS_IN" , 20, MYSQL_TYPE_LONG, 0, true, "Block_ops_in" , SKIP_OPEN_TABLE}, |
| 75 | {"BLOCK_OPS_OUT" , 20, MYSQL_TYPE_LONG, 0, true, "Block_ops_out" , SKIP_OPEN_TABLE}, |
| 76 | {"MESSAGES_SENT" , 20, MYSQL_TYPE_LONG, 0, true, "Messages_sent" , SKIP_OPEN_TABLE}, |
| 77 | {"MESSAGES_RECEIVED" , 20, MYSQL_TYPE_LONG, 0, true, "Messages_received" , SKIP_OPEN_TABLE}, |
| 78 | {"PAGE_FAULTS_MAJOR" , 20, MYSQL_TYPE_LONG, 0, true, "Page_faults_major" , SKIP_OPEN_TABLE}, |
| 79 | {"PAGE_FAULTS_MINOR" , 20, MYSQL_TYPE_LONG, 0, true, "Page_faults_minor" , SKIP_OPEN_TABLE}, |
| 80 | {"SWAPS" , 20, MYSQL_TYPE_LONG, 0, true, "Swaps" , SKIP_OPEN_TABLE}, |
| 81 | {"SOURCE_FUNCTION" , 30, MYSQL_TYPE_STRING, 0, true, "Source_function" , SKIP_OPEN_TABLE}, |
| 82 | {"SOURCE_FILE" , 20, MYSQL_TYPE_STRING, 0, true, "Source_file" , SKIP_OPEN_TABLE}, |
| 83 | {"SOURCE_LINE" , 20, MYSQL_TYPE_LONG, 0, true, "Source_line" , SKIP_OPEN_TABLE}, |
| 84 | {NULL, 0, MYSQL_TYPE_STRING, 0, true, NULL, 0} |
| 85 | }; |
| 86 | |
| 87 | |
| 88 | int make_profile_table_for_show(THD *thd, ST_SCHEMA_TABLE *schema_table) |
| 89 | { |
| 90 | uint profile_options = thd->lex->profile_options; |
| 91 | uint fields_include_condition_truth_values[]= { |
| 92 | FALSE, /* Query_id */ |
| 93 | FALSE, /* Seq */ |
| 94 | TRUE, /* Status */ |
| 95 | TRUE, /* Duration */ |
| 96 | profile_options & PROFILE_CPU, /* CPU_user */ |
| 97 | profile_options & PROFILE_CPU, /* CPU_system */ |
| 98 | profile_options & PROFILE_CONTEXT, /* Context_voluntary */ |
| 99 | profile_options & PROFILE_CONTEXT, /* Context_involuntary */ |
| 100 | profile_options & PROFILE_BLOCK_IO, /* Block_ops_in */ |
| 101 | profile_options & PROFILE_BLOCK_IO, /* Block_ops_out */ |
| 102 | profile_options & PROFILE_IPC, /* Messages_sent */ |
| 103 | profile_options & PROFILE_IPC, /* Messages_received */ |
| 104 | profile_options & PROFILE_PAGE_FAULTS, /* Page_faults_major */ |
| 105 | profile_options & PROFILE_PAGE_FAULTS, /* Page_faults_minor */ |
| 106 | profile_options & PROFILE_SWAPS, /* Swaps */ |
| 107 | profile_options & PROFILE_SOURCE, /* Source_function */ |
| 108 | profile_options & PROFILE_SOURCE, /* Source_file */ |
| 109 | profile_options & PROFILE_SOURCE, /* Source_line */ |
| 110 | }; |
| 111 | |
| 112 | ST_FIELD_INFO *field_info; |
| 113 | Name_resolution_context *context= &thd->lex->select_lex.context; |
| 114 | int i; |
| 115 | |
| 116 | for (i= 0; schema_table->fields_info[i].field_name != NULL; i++) |
| 117 | { |
| 118 | if (! fields_include_condition_truth_values[i]) |
| 119 | continue; |
| 120 | |
| 121 | field_info= &schema_table->fields_info[i]; |
| 122 | LEX_CSTRING field_name= {field_info->field_name, |
| 123 | strlen(field_info->field_name) }; |
| 124 | Item_field *field= new (thd->mem_root) Item_field(thd, context, |
| 125 | NullS, NullS, &field_name); |
| 126 | if (field) |
| 127 | { |
| 128 | field->set_name(thd, field_info->old_name, |
| 129 | (uint) strlen(field_info->old_name), |
| 130 | system_charset_info); |
| 131 | if (add_item_to_list(thd, field)) |
| 132 | return 1; |
| 133 | } |
| 134 | } |
| 135 | return 0; |
| 136 | } |
| 137 | |
| 138 | |
| 139 | #if defined(ENABLED_PROFILING) |
| 140 | |
| 141 | #define RUSAGE_USEC(tv) ((tv).tv_sec*1000*1000 + (tv).tv_usec) |
| 142 | #define RUSAGE_DIFF_USEC(tv1, tv2) (RUSAGE_USEC((tv1))-RUSAGE_USEC((tv2))) |
| 143 | |
| 144 | #ifdef _WIN32 |
| 145 | static ULONGLONG FileTimeToQuadWord(FILETIME *ft) |
| 146 | { |
| 147 | // Overlay FILETIME onto a ULONGLONG. |
| 148 | union { |
| 149 | ULONGLONG qwTime; |
| 150 | FILETIME ft; |
| 151 | } u; |
| 152 | |
| 153 | u.ft = *ft; |
| 154 | return u.qwTime; |
| 155 | } |
| 156 | |
| 157 | |
| 158 | // Get time difference between to FILETIME objects in seconds. |
| 159 | static double GetTimeDiffInSeconds(FILETIME *a, FILETIME *b) |
| 160 | { |
| 161 | return ((FileTimeToQuadWord(a) - FileTimeToQuadWord(b)) / 1e7); |
| 162 | } |
| 163 | #endif |
| 164 | |
| 165 | PROF_MEASUREMENT::PROF_MEASUREMENT(QUERY_PROFILE *profile_arg, const char |
| 166 | *status_arg) |
| 167 | :profile(profile_arg) |
| 168 | { |
| 169 | collect(); |
| 170 | set_label(status_arg, NULL, NULL, 0); |
| 171 | } |
| 172 | |
| 173 | PROF_MEASUREMENT::PROF_MEASUREMENT(QUERY_PROFILE *profile_arg, |
| 174 | const char *status_arg, |
| 175 | const char *function_arg, |
| 176 | const char *file_arg, |
| 177 | unsigned int line_arg) |
| 178 | :profile(profile_arg) |
| 179 | { |
| 180 | collect(); |
| 181 | set_label(status_arg, function_arg, file_arg, line_arg); |
| 182 | } |
| 183 | |
| 184 | PROF_MEASUREMENT::~PROF_MEASUREMENT() |
| 185 | { |
| 186 | my_free(allocated_status_memory); |
| 187 | status= function= file= NULL; |
| 188 | } |
| 189 | |
| 190 | void PROF_MEASUREMENT::set_label(const char *status_arg, |
| 191 | const char *function_arg, |
| 192 | const char *file_arg, unsigned int line_arg) |
| 193 | { |
| 194 | size_t sizes[3]; /* 3 == status+function+file */ |
| 195 | char *cursor; |
| 196 | |
| 197 | /* |
| 198 | Compute all the space we'll need to allocate one block for everything |
| 199 | we'll need, instead of N mallocs. |
| 200 | */ |
| 201 | sizes[0]= (status_arg == NULL) ? 0 : strlen(status_arg) + 1; |
| 202 | sizes[1]= (function_arg == NULL) ? 0 : strlen(function_arg) + 1; |
| 203 | sizes[2]= (file_arg == NULL) ? 0 : strlen(file_arg) + 1; |
| 204 | |
| 205 | allocated_status_memory= (char *) my_malloc(sizes[0] + sizes[1] + sizes[2], MYF(0)); |
| 206 | DBUG_ASSERT(allocated_status_memory != NULL); |
| 207 | |
| 208 | cursor= allocated_status_memory; |
| 209 | |
| 210 | if (status_arg != NULL) |
| 211 | { |
| 212 | strcpy(cursor, status_arg); |
| 213 | status= cursor; |
| 214 | cursor+= sizes[0]; |
| 215 | } |
| 216 | else |
| 217 | status= NULL; |
| 218 | |
| 219 | if (function_arg != NULL) |
| 220 | { |
| 221 | strcpy(cursor, function_arg); |
| 222 | function= cursor; |
| 223 | cursor+= sizes[1]; |
| 224 | } |
| 225 | else |
| 226 | function= NULL; |
| 227 | |
| 228 | if (file_arg != NULL) |
| 229 | { |
| 230 | strcpy(cursor, file_arg); |
| 231 | file= cursor; |
| 232 | cursor+= sizes[2]; |
| 233 | } |
| 234 | else |
| 235 | file= NULL; |
| 236 | |
| 237 | line= line_arg; |
| 238 | } |
| 239 | |
| 240 | /** |
| 241 | This updates the statistics for this moment of time. It captures the state |
| 242 | of the running system, so later we can compare points in time and infer what |
| 243 | happened in the mean time. It should only be called immediately upon |
| 244 | instantiation of this PROF_MEASUREMENT. |
| 245 | |
| 246 | @todo Implement resource capture for OSes not like BSD. |
| 247 | */ |
| 248 | void PROF_MEASUREMENT::collect() |
| 249 | { |
| 250 | time_usecs= my_interval_timer() / 1e3; /* ns to us */ |
| 251 | #ifdef HAVE_GETRUSAGE |
| 252 | getrusage(RUSAGE_SELF, &rusage); |
| 253 | #elif defined(_WIN32) |
| 254 | FILETIME ftDummy; |
| 255 | // NOTE: Get{Process|Thread}Times has a granularity of the clock interval, |
| 256 | // which is typically ~15ms. So intervals shorter than that will not be |
| 257 | // measurable by this function. |
| 258 | GetProcessTimes(GetCurrentProcess(), &ftDummy, &ftDummy, &ftKernel, &ftUser); |
| 259 | GetProcessIoCounters(GetCurrentProcess(), &io_count); |
| 260 | GetProcessMemoryInfo(GetCurrentProcess(), &mem_count, sizeof(mem_count)); |
| 261 | #endif |
| 262 | } |
| 263 | |
| 264 | |
| 265 | QUERY_PROFILE::QUERY_PROFILE(PROFILING *profiling_arg, const char *status_arg) |
| 266 | :profiling(profiling_arg), profiling_query_id(0), query_source(NULL) |
| 267 | { |
| 268 | m_seq_counter= 1; |
| 269 | PROF_MEASUREMENT *prof= new PROF_MEASUREMENT(this, status_arg); |
| 270 | prof->m_seq= m_seq_counter++; |
| 271 | m_start_time_usecs= prof->time_usecs; |
| 272 | m_end_time_usecs= m_start_time_usecs; |
| 273 | entries.push_back(prof); |
| 274 | } |
| 275 | |
| 276 | QUERY_PROFILE::~QUERY_PROFILE() |
| 277 | { |
| 278 | while (! entries.is_empty()) |
| 279 | delete entries.pop(); |
| 280 | |
| 281 | my_free(query_source); |
| 282 | } |
| 283 | |
| 284 | /** |
| 285 | @todo Provide a way to include the full text, as in SHOW PROCESSLIST. |
| 286 | */ |
| 287 | void QUERY_PROFILE::set_query_source(char *query_source_arg, size_t query_length_arg) |
| 288 | { |
| 289 | /* Truncate to avoid DoS attacks. */ |
| 290 | size_t length= MY_MIN(MAX_QUERY_LENGTH, query_length_arg); |
| 291 | |
| 292 | DBUG_ASSERT(query_source == NULL); /* we don't leak memory */ |
| 293 | if (query_source_arg != NULL) |
| 294 | query_source= my_strndup(query_source_arg, length, MYF(0)); |
| 295 | } |
| 296 | |
| 297 | void QUERY_PROFILE::new_status(const char *status_arg, |
| 298 | const char *function_arg, const char *file_arg, |
| 299 | unsigned int line_arg) |
| 300 | { |
| 301 | PROF_MEASUREMENT *prof; |
| 302 | DBUG_ENTER("QUERY_PROFILE::status" ); |
| 303 | |
| 304 | if (!status_arg) |
| 305 | DBUG_VOID_RETURN; |
| 306 | |
| 307 | if ((function_arg != NULL) && (file_arg != NULL)) |
| 308 | prof= new PROF_MEASUREMENT(this, status_arg, function_arg, base_name(file_arg), line_arg); |
| 309 | else |
| 310 | prof= new PROF_MEASUREMENT(this, status_arg); |
| 311 | |
| 312 | prof->m_seq= m_seq_counter++; |
| 313 | m_end_time_usecs= prof->time_usecs; |
| 314 | entries.push_back(prof); |
| 315 | |
| 316 | /* Maintain the query history size. */ |
| 317 | while (entries.elements > MAX_QUERY_HISTORY) |
| 318 | delete entries.pop(); |
| 319 | |
| 320 | DBUG_VOID_RETURN; |
| 321 | } |
| 322 | |
| 323 | |
| 324 | |
| 325 | PROFILING::PROFILING() |
| 326 | :profile_id_counter(1), current(NULL), last(NULL) |
| 327 | { |
| 328 | } |
| 329 | |
| 330 | PROFILING::~PROFILING() |
| 331 | { |
| 332 | restart(); |
| 333 | } |
| 334 | |
| 335 | /* |
| 336 | Restart profiling from scratch |
| 337 | */ |
| 338 | |
| 339 | void PROFILING::restart() |
| 340 | { |
| 341 | while (! history.is_empty()) |
| 342 | delete history.pop(); |
| 343 | |
| 344 | if (current != NULL) |
| 345 | delete current; |
| 346 | /* Ensure that profiling object can be reused */ |
| 347 | profile_id_counter= 1; |
| 348 | current= NULL; |
| 349 | last= NULL; |
| 350 | } |
| 351 | |
| 352 | |
| 353 | /** |
| 354 | Throw away the current profile, because it's useless or unwanted |
| 355 | or corrupted. |
| 356 | */ |
| 357 | void PROFILING::discard_current_query() |
| 358 | { |
| 359 | DBUG_ENTER("PROFILING::discard_current_profile" ); |
| 360 | |
| 361 | delete current; |
| 362 | current= NULL; |
| 363 | |
| 364 | DBUG_VOID_RETURN; |
| 365 | } |
| 366 | |
| 367 | /** |
| 368 | Try to save the current profile entry, clean up the data if it shouldn't be |
| 369 | saved, and maintain the profile history size. Naturally, this may not |
| 370 | succeed if the profile was previously discarded, and that's expected. |
| 371 | */ |
| 372 | void PROFILING::finish_current_query_impl() |
| 373 | { |
| 374 | DBUG_ENTER("PROFILING::finish_current_profile" ); |
| 375 | DBUG_ASSERT(current); |
| 376 | |
| 377 | /* The last fence-post, so we can support the span before this. */ |
| 378 | status_change("ending" , NULL, NULL, 0); |
| 379 | |
| 380 | if (enabled && /* ON at end? */ |
| 381 | (current->query_source != NULL) && |
| 382 | (! current->entries.is_empty())) |
| 383 | { |
| 384 | current->profiling_query_id= next_profile_id(); /* assign an id */ |
| 385 | |
| 386 | history.push_back(current); |
| 387 | last= current; /* never contains something that is not in the history. */ |
| 388 | |
| 389 | /* Maintain the history size. */ |
| 390 | while (history.elements > thd->variables.profiling_history_size) |
| 391 | delete history.pop(); |
| 392 | } |
| 393 | else |
| 394 | delete current; |
| 395 | |
| 396 | current= NULL; |
| 397 | DBUG_VOID_RETURN; |
| 398 | } |
| 399 | |
| 400 | bool PROFILING::show_profiles() |
| 401 | { |
| 402 | QUERY_PROFILE *prof; |
| 403 | List<Item> field_list; |
| 404 | MEM_ROOT *mem_root= thd->mem_root; |
| 405 | SELECT_LEX *sel= &thd->lex->select_lex; |
| 406 | SELECT_LEX_UNIT *unit= &thd->lex->unit; |
| 407 | ha_rows idx= 0; |
| 408 | Protocol *protocol= thd->protocol; |
| 409 | void *iterator; |
| 410 | DBUG_ENTER("PROFILING::show_profiles" ); |
| 411 | |
| 412 | field_list.push_back(new (mem_root) |
| 413 | Item_return_int(thd, "Query_ID" , 10, |
| 414 | MYSQL_TYPE_LONG), |
| 415 | mem_root); |
| 416 | field_list.push_back(new (mem_root) |
| 417 | Item_return_int(thd, "Duration" , |
| 418 | TIME_FLOAT_DIGITS - 1, |
| 419 | MYSQL_TYPE_DOUBLE), |
| 420 | mem_root); |
| 421 | field_list.push_back(new (mem_root) Item_empty_string(thd, "Query" , 40), |
| 422 | mem_root); |
| 423 | |
| 424 | if (protocol->send_result_set_metadata(&field_list, |
| 425 | Protocol::SEND_NUM_ROWS | |
| 426 | Protocol::SEND_EOF)) |
| 427 | DBUG_RETURN(TRUE); |
| 428 | |
| 429 | unit->set_limit(sel); |
| 430 | |
| 431 | for (iterator= history.new_iterator(); |
| 432 | iterator != NULL; |
| 433 | iterator= history.iterator_next(iterator)) |
| 434 | { |
| 435 | prof= history.iterator_value(iterator); |
| 436 | |
| 437 | String elapsed; |
| 438 | |
| 439 | double query_time_usecs= prof->m_end_time_usecs - prof->m_start_time_usecs; |
| 440 | |
| 441 | if (++idx <= unit->offset_limit_cnt) |
| 442 | continue; |
| 443 | if (idx > unit->select_limit_cnt) |
| 444 | break; |
| 445 | |
| 446 | protocol->prepare_for_resend(); |
| 447 | protocol->store((uint32)(prof->profiling_query_id)); |
| 448 | protocol->store((double)(query_time_usecs/(1000.0*1000)), |
| 449 | (uint32) TIME_FLOAT_DIGITS-1, &elapsed); |
| 450 | if (prof->query_source != NULL) |
| 451 | protocol->store(prof->query_source, strlen(prof->query_source), |
| 452 | system_charset_info); |
| 453 | else |
| 454 | protocol->store_null(); |
| 455 | |
| 456 | if (protocol->write()) |
| 457 | DBUG_RETURN(TRUE); |
| 458 | } |
| 459 | my_eof(thd); |
| 460 | DBUG_RETURN(FALSE); |
| 461 | } |
| 462 | |
| 463 | /** |
| 464 | Fill the information schema table, "query_profile", as defined in show.cc . |
| 465 | There are two ways to get to this function: Selecting from the information |
| 466 | schema, and a SHOW command. |
| 467 | */ |
| 468 | int PROFILING::fill_statistics_info(THD *thd_arg, TABLE_LIST *tables, Item *cond) |
| 469 | { |
| 470 | DBUG_ENTER("PROFILING::fill_statistics_info" ); |
| 471 | TABLE *table= tables->table; |
| 472 | ulonglong row_number= 0; |
| 473 | |
| 474 | QUERY_PROFILE *query; |
| 475 | /* Go through each query in this thread's stored history... */ |
| 476 | void *history_iterator; |
| 477 | for (history_iterator= history.new_iterator(); |
| 478 | history_iterator != NULL; |
| 479 | history_iterator= history.iterator_next(history_iterator)) |
| 480 | { |
| 481 | query= history.iterator_value(history_iterator); |
| 482 | |
| 483 | /* |
| 484 | Because we put all profiling info into a table that may be reordered, let |
| 485 | us also include a numbering of each state per query. The query_id and |
| 486 | the "seq" together are unique. |
| 487 | */ |
| 488 | ulong seq; |
| 489 | |
| 490 | void *entry_iterator; |
| 491 | PROF_MEASUREMENT *entry, *previous= NULL; |
| 492 | /* ...and for each query, go through all its state-change steps. */ |
| 493 | for (entry_iterator= query->entries.new_iterator(); |
| 494 | entry_iterator != NULL; |
| 495 | entry_iterator= query->entries.iterator_next(entry_iterator), |
| 496 | previous=entry, row_number++) |
| 497 | { |
| 498 | entry= query->entries.iterator_value(entry_iterator); |
| 499 | seq= entry->m_seq; |
| 500 | |
| 501 | /* Skip the first. We count spans of fence, not fence-posts. */ |
| 502 | if (previous == NULL) continue; |
| 503 | |
| 504 | if (thd_arg->lex->sql_command == SQLCOM_SHOW_PROFILE) |
| 505 | { |
| 506 | /* |
| 507 | We got here via a SHOW command. That means that we stored |
| 508 | information about the query we wish to show and that isn't |
| 509 | in a WHERE clause at a higher level to filter out rows we |
| 510 | wish to exclude. |
| 511 | |
| 512 | Because that functionality isn't available in the server yet, |
| 513 | we must filter here, at the wrong level. Once one can con- |
| 514 | struct where and having conditions at the SQL layer, then this |
| 515 | condition should be ripped out. |
| 516 | */ |
| 517 | if (thd_arg->lex->profile_query_id == 0) /* 0 == show final query */ |
| 518 | { |
| 519 | if (query != last) |
| 520 | continue; |
| 521 | } |
| 522 | else |
| 523 | { |
| 524 | if (thd_arg->lex->profile_query_id != query->profiling_query_id) |
| 525 | continue; |
| 526 | } |
| 527 | } |
| 528 | |
| 529 | /* Set default values for this row. */ |
| 530 | restore_record(table, s->default_values); |
| 531 | |
| 532 | /* |
| 533 | The order of these fields is set by the query_profile_statistics_info |
| 534 | array. |
| 535 | */ |
| 536 | table->field[0]->store((ulonglong) query->profiling_query_id, TRUE); |
| 537 | table->field[1]->store((ulonglong) seq, TRUE); /* the step in the sequence */ |
| 538 | /* |
| 539 | This entry, n, has a point in time, T(n), and a status phrase, S(n). |
| 540 | The status phrase S(n) describes the period of time that begins at |
| 541 | T(n). The previous status phrase S(n-1) describes the period of time |
| 542 | that starts at T(n-1) and ends at T(n). Since we want to describe the |
| 543 | time that a status phrase took T(n)-T(n-1), this line must describe the |
| 544 | previous status. |
| 545 | */ |
| 546 | table->field[2]->store(previous->status, strlen(previous->status), |
| 547 | system_charset_info); |
| 548 | |
| 549 | my_decimal duration_decimal; |
| 550 | double2my_decimal(E_DEC_FATAL_ERROR, |
| 551 | (entry->time_usecs-previous->time_usecs)/(1000.0*1000), |
| 552 | &duration_decimal); |
| 553 | |
| 554 | table->field[3]->store_decimal(&duration_decimal); |
| 555 | |
| 556 | |
| 557 | #ifdef HAVE_GETRUSAGE |
| 558 | |
| 559 | my_decimal cpu_utime_decimal, cpu_stime_decimal; |
| 560 | |
| 561 | double2my_decimal(E_DEC_FATAL_ERROR, |
| 562 | RUSAGE_DIFF_USEC(entry->rusage.ru_utime, |
| 563 | previous->rusage.ru_utime) / |
| 564 | (1000.0*1000), |
| 565 | &cpu_utime_decimal); |
| 566 | |
| 567 | double2my_decimal(E_DEC_FATAL_ERROR, |
| 568 | RUSAGE_DIFF_USEC(entry->rusage.ru_stime, |
| 569 | previous->rusage.ru_stime) / |
| 570 | (1000.0*1000), |
| 571 | &cpu_stime_decimal); |
| 572 | |
| 573 | table->field[4]->store_decimal(&cpu_utime_decimal); |
| 574 | table->field[5]->store_decimal(&cpu_stime_decimal); |
| 575 | table->field[4]->set_notnull(); |
| 576 | table->field[5]->set_notnull(); |
| 577 | #elif defined(_WIN32) |
| 578 | my_decimal cpu_utime_decimal, cpu_stime_decimal; |
| 579 | |
| 580 | double2my_decimal(E_DEC_FATAL_ERROR, |
| 581 | GetTimeDiffInSeconds(&entry->ftUser, |
| 582 | &previous->ftUser), |
| 583 | &cpu_utime_decimal); |
| 584 | double2my_decimal(E_DEC_FATAL_ERROR, |
| 585 | GetTimeDiffInSeconds(&entry->ftKernel, |
| 586 | &previous->ftKernel), |
| 587 | &cpu_stime_decimal); |
| 588 | |
| 589 | // Store the result. |
| 590 | table->field[4]->store_decimal(&cpu_utime_decimal); |
| 591 | table->field[5]->store_decimal(&cpu_stime_decimal); |
| 592 | table->field[4]->set_notnull(); |
| 593 | table->field[5]->set_notnull(); |
| 594 | #else |
| 595 | /* TODO: Add CPU-usage info for non-BSD systems */ |
| 596 | #endif |
| 597 | |
| 598 | #ifdef HAVE_GETRUSAGE |
| 599 | table->field[6]->store((uint32)(entry->rusage.ru_nvcsw - |
| 600 | previous->rusage.ru_nvcsw)); |
| 601 | table->field[6]->set_notnull(); |
| 602 | table->field[7]->store((uint32)(entry->rusage.ru_nivcsw - |
| 603 | previous->rusage.ru_nivcsw)); |
| 604 | table->field[7]->set_notnull(); |
| 605 | #else |
| 606 | /* TODO: Add context switch info for non-BSD systems */ |
| 607 | #endif |
| 608 | |
| 609 | #ifdef HAVE_GETRUSAGE |
| 610 | table->field[8]->store((uint32)(entry->rusage.ru_inblock - |
| 611 | previous->rusage.ru_inblock)); |
| 612 | table->field[8]->set_notnull(); |
| 613 | table->field[9]->store((uint32)(entry->rusage.ru_oublock - |
| 614 | previous->rusage.ru_oublock)); |
| 615 | table->field[9]->set_notnull(); |
| 616 | #elif defined(__WIN__) |
| 617 | ULONGLONG reads_delta = entry->io_count.ReadOperationCount - |
| 618 | previous->io_count.ReadOperationCount; |
| 619 | ULONGLONG writes_delta = entry->io_count.WriteOperationCount - |
| 620 | previous->io_count.WriteOperationCount; |
| 621 | |
| 622 | table->field[8]->store((uint32)reads_delta); |
| 623 | table->field[8]->set_notnull(); |
| 624 | |
| 625 | table->field[9]->store((uint32)writes_delta); |
| 626 | table->field[9]->set_notnull(); |
| 627 | #else |
| 628 | /* TODO: Add block IO info for non-BSD systems */ |
| 629 | #endif |
| 630 | |
| 631 | #ifdef HAVE_GETRUSAGE |
| 632 | table->field[10]->store((uint32)(entry->rusage.ru_msgsnd - |
| 633 | previous->rusage.ru_msgsnd), true); |
| 634 | table->field[10]->set_notnull(); |
| 635 | table->field[11]->store((uint32)(entry->rusage.ru_msgrcv - |
| 636 | previous->rusage.ru_msgrcv), true); |
| 637 | table->field[11]->set_notnull(); |
| 638 | #else |
| 639 | /* TODO: Add message info for non-BSD systems */ |
| 640 | #endif |
| 641 | |
| 642 | #ifdef HAVE_GETRUSAGE |
| 643 | table->field[12]->store((uint32)(entry->rusage.ru_majflt - |
| 644 | previous->rusage.ru_majflt), true); |
| 645 | table->field[12]->set_notnull(); |
| 646 | table->field[13]->store((uint32)(entry->rusage.ru_minflt - |
| 647 | previous->rusage.ru_minflt), true); |
| 648 | table->field[13]->set_notnull(); |
| 649 | #elif defined(__WIN__) |
| 650 | /* Windows APIs don't easily distinguish between hard and soft page |
| 651 | faults, so we just fill the 'major' column and leave the second NULL. |
| 652 | */ |
| 653 | table->field[12]->store((uint32)(entry->mem_count.PageFaultCount - |
| 654 | previous->mem_count.PageFaultCount), true); |
| 655 | table->field[12]->set_notnull(); |
| 656 | #else |
| 657 | /* TODO: Add page fault info for non-BSD systems */ |
| 658 | #endif |
| 659 | |
| 660 | #ifdef HAVE_GETRUSAGE |
| 661 | table->field[14]->store((uint32)(entry->rusage.ru_nswap - |
| 662 | previous->rusage.ru_nswap), true); |
| 663 | table->field[14]->set_notnull(); |
| 664 | #else |
| 665 | /* TODO: Add swap info for non-BSD systems */ |
| 666 | #endif |
| 667 | |
| 668 | /* Emit the location that started this step, not that ended it. */ |
| 669 | if ((previous->function != NULL) && (previous->file != NULL)) |
| 670 | { |
| 671 | table->field[15]->store(previous->function, strlen(previous->function), |
| 672 | system_charset_info); |
| 673 | table->field[15]->set_notnull(); |
| 674 | table->field[16]->store(previous->file, strlen(previous->file), system_charset_info); |
| 675 | table->field[16]->set_notnull(); |
| 676 | table->field[17]->store(previous->line, true); |
| 677 | table->field[17]->set_notnull(); |
| 678 | } |
| 679 | |
| 680 | if (schema_table_store_record(thd_arg, table)) |
| 681 | DBUG_RETURN(1); |
| 682 | |
| 683 | } |
| 684 | } |
| 685 | |
| 686 | DBUG_RETURN(0); |
| 687 | } |
| 688 | |
| 689 | |
| 690 | void PROFILING::reset() |
| 691 | { |
| 692 | enabled= (thd->variables.option_bits & OPTION_PROFILING) != 0; |
| 693 | } |
| 694 | #endif /* ENABLED_PROFILING */ |
| 695 | |