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