1/* Copyright (c) 2000, 2010, 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/* Write some debug info */
18
19#include "mariadb.h"
20#include "sql_priv.h"
21#include "unireg.h"
22#include "sql_test.h"
23#include "sql_base.h"
24#include "sql_show.h" // calc_sum_of_all_status
25#include "sql_select.h"
26#include "keycaches.h"
27#include <hash.h>
28#include <thr_alarm.h>
29#if defined(HAVE_MALLINFO) && defined(HAVE_MALLOC_H)
30#include <malloc.h>
31#elif defined(HAVE_MALLINFO) && defined(HAVE_SYS_MALLOC_H)
32#include <sys/malloc.h>
33#endif
34
35#ifdef HAVE_EVENT_SCHEDULER
36#include "events.h"
37#endif
38
39static const char *lock_descriptions[] =
40{
41 /* TL_UNLOCK */ "No lock",
42 /* TL_READ_DEFAULT */ NULL,
43 /* TL_READ */ "Low priority read lock",
44 /* TL_READ_WITH_SHARED_LOCKS */ "Shared read lock",
45 /* TL_READ_HIGH_PRIORITY */ "High priority read lock",
46 /* TL_READ_NO_INSERT */ "Read lock without concurrent inserts",
47 /* TL_WRITE_ALLOW_WRITE */ "Write lock that allows other writers",
48 /* TL_WRITE_CONCURRENT_INSERT */ "Concurrent insert lock",
49 /* TL_WRITE_DELAYED */ "Lock used by delayed insert",
50 /* TL_WRITE_DEFAULT */ NULL,
51 /* TL_WRITE_LOW_PRIORITY */ "Low priority write lock",
52 /* TL_WRITE */ "High priority write lock",
53 /* TL_WRITE_ONLY */ "Highest priority write lock"
54};
55
56
57#ifndef DBUG_OFF
58
59void
60print_where(COND *cond,const char *info, enum_query_type query_type)
61{
62 char buff[1024];
63 String str(buff,(uint32) sizeof(buff), system_charset_info);
64 str.length(0);
65 str.extra_allocation(1024);
66 if (cond)
67 cond->print(&str, query_type);
68
69 DBUG_LOCK_FILE;
70 (void) fprintf(DBUG_FILE,"\nWHERE:(%s) %p ", info, cond);
71 (void) fputs(str.c_ptr_safe(),DBUG_FILE);
72 (void) fputc('\n',DBUG_FILE);
73 DBUG_UNLOCK_FILE;
74}
75
76#ifdef EXTRA_DEBUG
77 /* This is for debugging purposes */
78static my_bool print_cached_tables_callback(TDC_element *element,
79 void *arg __attribute__((unused)))
80{
81 TABLE *entry;
82
83 mysql_mutex_lock(&element->LOCK_table_share);
84 All_share_tables_list::Iterator it(element->all_tables);
85 while ((entry= it++))
86 {
87 THD *in_use= entry->in_use;
88 printf("%-14.14s %-32s%6lu%8ld%6d %s\n",
89 entry->s->db.str, entry->s->table_name.str,
90 (ulong) element->version,
91 in_use ? (long) in_use->thread_id : (long) 0,
92 entry->db_stat ? 1 : 0,
93 in_use ? lock_descriptions[(int)entry->reginfo.lock_type] :
94 "Not in use");
95 }
96 mysql_mutex_unlock(&element->LOCK_table_share);
97 return FALSE;
98}
99
100
101static void print_cached_tables(void)
102{
103 compile_time_assert(TL_WRITE_ONLY+1 == array_elements(lock_descriptions));
104
105 /* purecov: begin tested */
106 puts("DB Table Version Thread Open Lock");
107
108 tdc_iterate(0, (my_hash_walk_action) print_cached_tables_callback, NULL, true);
109
110 printf("\nCurrent refresh version: %ld\n",
111 (long) tdc_refresh_version());
112 fflush(stdout);
113 /* purecov: end */
114 return;
115}
116#endif
117
118
119void TEST_filesort(SORT_FIELD *sortorder,uint s_length)
120{
121 char buff[256],buff2[256];
122 String str(buff,sizeof(buff),system_charset_info);
123 String out(buff2,sizeof(buff2),system_charset_info);
124 const char *sep;
125 DBUG_ENTER("TEST_filesort");
126
127 out.length(0);
128 for (sep=""; s_length-- ; sortorder++, sep=" ")
129 {
130 out.append(sep);
131 if (sortorder->reverse)
132 out.append('-');
133 if (sortorder->field)
134 {
135 if (sortorder->field->table_name)
136 {
137 out.append(*sortorder->field->table_name);
138 out.append('.');
139 }
140 out.append(sortorder->field->field_name.str ?
141 sortorder->field->field_name.str :
142 "tmp_table_column");
143 }
144 else
145 {
146 str.length(0);
147 sortorder->item->print(&str, QT_ORDINARY);
148 out.append(str);
149 }
150 }
151 DBUG_LOCK_FILE;
152 (void) fputs("\nInfo about FILESORT\n",DBUG_FILE);
153 fprintf(DBUG_FILE,"Sortorder: %s\n",out.c_ptr_safe());
154 DBUG_UNLOCK_FILE;
155 DBUG_VOID_RETURN;
156}
157
158
159void
160TEST_join(JOIN *join)
161{
162 uint ref;
163 int i;
164 List_iterator<JOIN_TAB_RANGE> it(join->join_tab_ranges);
165 JOIN_TAB_RANGE *jt_range;
166 DBUG_ENTER("TEST_join");
167
168 DBUG_LOCK_FILE;
169 (void) fputs("\nInfo about JOIN\n",DBUG_FILE);
170 while ((jt_range= it++))
171 {
172 /*
173 Assemble results of all the calls to full_name() first,
174 in order not to garble the tabular output below.
175 */
176 String ref_key_parts[MAX_TABLES];
177 int tables_in_range= (int)(jt_range->end - jt_range->start);
178 for (i= 0; i < tables_in_range; i++)
179 {
180 JOIN_TAB *tab= jt_range->start + i;
181 for (ref= 0; ref < tab->ref.key_parts; ref++)
182 {
183 ref_key_parts[i].append(tab->ref.items[ref]->full_name());
184 ref_key_parts[i].append(" ");
185 }
186 }
187
188 for (i= 0; i < tables_in_range; i++)
189 {
190 JOIN_TAB *tab= jt_range->start + i;
191 TABLE *form=tab->table;
192 char key_map_buff[128];
193 fprintf(DBUG_FILE,"%-16.16s type: %-7s q_keys: %s refs: %d key: %d len: %d\n",
194 form->alias.c_ptr(),
195 join_type_str[tab->type],
196 tab->keys.print(key_map_buff),
197 tab->ref.key_parts,
198 tab->ref.key,
199 tab->ref.key_length);
200 if (tab->select)
201 {
202 char buf[MAX_KEY/8+1];
203 if (tab->use_quick == 2)
204 fprintf(DBUG_FILE,
205 " quick select checked for each record (keys: %s)\n",
206 tab->select->quick_keys.print(buf));
207 else if (tab->select->quick)
208 {
209 fprintf(DBUG_FILE, " quick select used:\n");
210 tab->select->quick->dbug_dump(18, FALSE);
211 }
212 else
213 (void)fputs(" select used\n",DBUG_FILE);
214 }
215 if (tab->ref.key_parts)
216 {
217 fprintf(DBUG_FILE,
218 " refs: %s\n", ref_key_parts[i].c_ptr_safe());
219 }
220 }
221 (void)fputs("\n",DBUG_FILE);
222 }
223 DBUG_UNLOCK_FILE;
224 DBUG_VOID_RETURN;
225}
226
227
228#define FT_KEYPART (MAX_FIELDS+10)
229
230static void print_keyuse(KEYUSE *keyuse)
231{
232 char buff[256];
233 char buf2[64];
234 const char *fieldname;
235 JOIN_TAB *join_tab= keyuse->table->reginfo.join_tab;
236 KEY *key_info= join_tab->get_keyinfo_by_key_no(keyuse->key);
237 String str(buff,(uint32) sizeof(buff), system_charset_info);
238 str.length(0);
239 keyuse->val->print(&str, QT_ORDINARY);
240 str.append('\0');
241 if (keyuse->is_for_hash_join())
242 fieldname= keyuse->table->field[keyuse->keypart]->field_name.str;
243 else if (keyuse->keypart == FT_KEYPART)
244 fieldname= "FT_KEYPART";
245 else
246 fieldname= key_info->key_part[keyuse->keypart].field->field_name.str;
247 ll2str(keyuse->used_tables, buf2, 16, 0);
248 fprintf(DBUG_FILE, "KEYUSE: %s.%s=%s optimize: %u used_tables: %s "
249 "ref_table_rows: %lu keypart_map: %0lx\n",
250 keyuse->table->alias.c_ptr(), fieldname, str.ptr(),
251 (uint) keyuse->optimize, buf2, (ulong) keyuse->ref_table_rows,
252 (ulong) keyuse->keypart_map);
253}
254
255
256/* purecov: begin inspected */
257void print_keyuse_array(DYNAMIC_ARRAY *keyuse_array)
258{
259 DBUG_LOCK_FILE;
260 fprintf(DBUG_FILE, "KEYUSE array (%d elements)\n", keyuse_array->elements);
261 for(uint i=0; i < keyuse_array->elements; i++)
262 print_keyuse((KEYUSE*)dynamic_array_ptr(keyuse_array, i));
263 DBUG_UNLOCK_FILE;
264}
265
266
267/*
268 Print the current state during query optimization.
269
270 SYNOPSIS
271 print_plan()
272 join pointer to the structure providing all context info for
273 the query
274 read_time the cost of the best partial plan
275 record_count estimate for the number of records returned by the best
276 partial plan
277 idx length of the partial QEP in 'join->positions';
278 also an index in the array 'join->best_ref';
279 info comment string to appear above the printout
280
281 DESCRIPTION
282 This function prints to the log file DBUG_FILE the members of 'join' that
283 are used during query optimization (join->positions, join->best_positions,
284 and join->best_ref) and few other related variables (read_time,
285 record_count).
286 Useful to trace query optimizer functions.
287
288 RETURN
289 None
290*/
291
292void
293print_plan(JOIN* join, uint idx, double record_count, double read_time,
294 double current_read_time, const char *info)
295{
296 uint i;
297 POSITION pos;
298 JOIN_TAB *join_table;
299 JOIN_TAB **plan_nodes;
300 TABLE* table;
301
302 if (info == 0)
303 info= "";
304
305 DBUG_LOCK_FILE;
306 if (join->best_read == DBL_MAX)
307 {
308 fprintf(DBUG_FILE,
309 "%s; idx: %u best: DBL_MAX atime: %g itime: %g count: %g\n",
310 info, idx, current_read_time, read_time, record_count);
311 }
312 else
313 {
314 fprintf(DBUG_FILE,
315 "%s; idx :%u best: %g accumulated: %g increment: %g count: %g\n",
316 info, idx, join->best_read, current_read_time, read_time,
317 record_count);
318 }
319
320 /* Print the tables in JOIN->positions */
321 fputs(" POSITIONS: ", DBUG_FILE);
322 for (i= 0; i < idx ; i++)
323 {
324 pos = join->positions[i];
325 table= pos.table->table;
326 if (table)
327 fputs(table->s->table_name.str, DBUG_FILE);
328 fputc(' ', DBUG_FILE);
329 }
330 fputc('\n', DBUG_FILE);
331
332 /*
333 Print the tables in JOIN->best_positions only if at least one complete plan
334 has been found. An indicator for this is the value of 'join->best_read'.
335 */
336 if (join->best_read < DBL_MAX)
337 {
338 fputs("BEST_POSITIONS: ", DBUG_FILE);
339 for (i= 0; i < idx ; i++)
340 {
341 pos= join->best_positions[i];
342 table= pos.table->table;
343 if (table)
344 fputs(table->s->table_name.str, DBUG_FILE);
345 fputc(' ', DBUG_FILE);
346 }
347 }
348 fputc('\n', DBUG_FILE);
349
350 /* Print the tables in JOIN->best_ref */
351 fputs(" BEST_REF: ", DBUG_FILE);
352 for (plan_nodes= join->best_ref ; *plan_nodes ; plan_nodes++)
353 {
354 join_table= (*plan_nodes);
355 fputs(join_table->table->s->table_name.str, DBUG_FILE);
356 fprintf(DBUG_FILE, "(%lu,%lu,%lu)",
357 (ulong) join_table->found_records,
358 (ulong) join_table->records,
359 (ulong) join_table->read_time);
360 fputc(' ', DBUG_FILE);
361 }
362 fputc('\n', DBUG_FILE);
363
364 DBUG_UNLOCK_FILE;
365}
366
367
368void print_sjm(SJ_MATERIALIZATION_INFO *sjm)
369{
370 DBUG_LOCK_FILE;
371 fprintf(DBUG_FILE, "\nsemi-join nest{\n");
372 fprintf(DBUG_FILE, " tables { \n");
373 for (uint i= 0;i < sjm->tables; i++)
374 {
375 fprintf(DBUG_FILE, " %s%s\n",
376 sjm->positions[i].table->table->alias.c_ptr(),
377 (i == sjm->tables -1)? "": ",");
378 }
379 fprintf(DBUG_FILE, " }\n");
380 fprintf(DBUG_FILE, " materialize_cost= %g\n",
381 sjm->materialization_cost.total_cost());
382 fprintf(DBUG_FILE, " rows= %g\n", sjm->rows);
383 fprintf(DBUG_FILE, "}\n");
384 DBUG_UNLOCK_FILE;
385}
386/* purecov: end */
387
388/*
389 Debugging help: force List<...>::elem function not be removed as unused.
390*/
391Item* (List<Item>:: *dbug_list_item_elem_ptr)(uint)= &List<Item>::elem;
392Item_equal* (List<Item_equal>:: *dbug_list_item_equal_elem_ptr)(uint)=
393 &List<Item_equal>::elem;
394TABLE_LIST* (List<TABLE_LIST>:: *dbug_list_table_list_elem_ptr)(uint) =
395 &List<TABLE_LIST>::elem;
396
397#endif
398
399typedef struct st_debug_lock
400{
401 ulong thread_id;
402 char table_name[FN_REFLEN];
403 bool waiting;
404 const char *lock_text;
405 enum thr_lock_type type;
406} TABLE_LOCK_INFO;
407
408C_MODE_START
409static int dl_compare(const void *p1, const void *p2)
410{
411 TABLE_LOCK_INFO *a, *b;
412
413 a= (TABLE_LOCK_INFO *) p1;
414 b= (TABLE_LOCK_INFO *) p2;
415
416 if (a->thread_id > b->thread_id)
417 return 1;
418 if (a->thread_id < b->thread_id)
419 return -1;
420 if (a->waiting == b->waiting)
421 return 0;
422 else if (a->waiting)
423 return -1;
424 return 1;
425}
426C_MODE_END
427
428
429static void push_locks_into_array(DYNAMIC_ARRAY *ar, THR_LOCK_DATA *data,
430 bool wait, const char *text)
431{
432 if (data)
433 {
434 TABLE *table=(TABLE *)data->debug_print_param;
435 if (table && table->s->tmp_table == NO_TMP_TABLE)
436 {
437 TABLE_LOCK_INFO table_lock_info;
438 table_lock_info.thread_id= (ulong)table->in_use->thread_id;
439 memcpy(table_lock_info.table_name, table->s->table_cache_key.str,
440 table->s->table_cache_key.length);
441 table_lock_info.table_name[strlen(table_lock_info.table_name)]='.';
442 table_lock_info.waiting=wait;
443 table_lock_info.lock_text=text;
444 // lock_type is also obtainable from THR_LOCK_DATA
445 table_lock_info.type=table->reginfo.lock_type;
446 (void) push_dynamic(ar,(uchar*) &table_lock_info);
447 }
448 }
449}
450
451
452/*
453 Regarding MERGE tables:
454
455 For now, the best option is to use the common TABLE *pointer for all
456 cases; The drawback is that for MERGE tables we will see many locks
457 for the merge tables even if some of them are for individual tables.
458
459 The way to solve this is to add to 'THR_LOCK' structure a pointer to
460 the filename and use this when printing the data.
461 (We can for now ignore this and just print the same name for all merge
462 table parts; Please add the above as a comment to the display_lock
463 function so that we can easily add this if we ever need this.
464*/
465
466static void display_table_locks(void)
467{
468 LIST *list;
469 void *saved_base;
470 DYNAMIC_ARRAY saved_table_locks;
471
472 (void) my_init_dynamic_array(&saved_table_locks,sizeof(TABLE_LOCK_INFO),
473 tc_records() + 20, 50, MYF(0));
474 mysql_mutex_lock(&THR_LOCK_lock);
475 for (list= thr_lock_thread_list; list; list= list_rest(list))
476 {
477 THR_LOCK *lock=(THR_LOCK*) list->data;
478
479 mysql_mutex_lock(&lock->mutex);
480 push_locks_into_array(&saved_table_locks, lock->write.data, FALSE,
481 "Locked - write");
482 push_locks_into_array(&saved_table_locks, lock->write_wait.data, TRUE,
483 "Waiting - write");
484 push_locks_into_array(&saved_table_locks, lock->read.data, FALSE,
485 "Locked - read");
486 push_locks_into_array(&saved_table_locks, lock->read_wait.data, TRUE,
487 "Waiting - read");
488 mysql_mutex_unlock(&lock->mutex);
489 }
490 mysql_mutex_unlock(&THR_LOCK_lock);
491
492 if (!saved_table_locks.elements)
493 goto end;
494
495 saved_base= dynamic_element(&saved_table_locks, 0, TABLE_LOCK_INFO *);
496 my_qsort(saved_base, saved_table_locks.elements, sizeof(TABLE_LOCK_INFO),
497 dl_compare);
498 freeze_size(&saved_table_locks);
499
500 puts("\nThread database.table_name Locked/Waiting Lock_type\n");
501
502 unsigned int i;
503 for (i=0 ; i < saved_table_locks.elements ; i++)
504 {
505 TABLE_LOCK_INFO *dl_ptr=dynamic_element(&saved_table_locks,i,TABLE_LOCK_INFO*);
506 printf("%-8ld%-28.28s%-22s%s\n",
507 dl_ptr->thread_id,dl_ptr->table_name,dl_ptr->lock_text,lock_descriptions[(int)dl_ptr->type]);
508 }
509 puts("\n\n");
510end:
511 delete_dynamic(&saved_table_locks);
512}
513
514C_MODE_START
515static int print_key_cache_status(const char *name, KEY_CACHE *key_cache,
516 void *unused __attribute__((unused)))
517{
518 char llbuff1[22];
519 char llbuff2[22];
520 char llbuff3[22];
521 char llbuff4[22];
522
523 if (!key_cache->key_cache_inited)
524 {
525 printf("%s: Not in use\n", name);
526 }
527 else
528 {
529 KEY_CACHE_STATISTICS stats;
530 get_key_cache_statistics(key_cache, 0, &stats);
531
532 printf("%s\n\
533Buffer_size: %10lu\n\
534Block_size: %10lu\n\
535Division_limit: %10lu\n\
536Age_threshold: %10lu\n\
537Partitions: %10lu\n\
538blocks used: %10lu\n\
539not flushed: %10lu\n\
540w_requests: %10s\n\
541writes: %10s\n\
542r_requests: %10s\n\
543reads: %10s\n\n",
544 name,
545 (ulong)key_cache->param_buff_size,
546 (ulong)key_cache->param_block_size,
547 (ulong)key_cache->param_division_limit,
548 (ulong)key_cache->param_age_threshold,
549 (ulong)key_cache->param_partitions,
550 (ulong)stats.blocks_used,
551 (ulong)stats.blocks_changed,
552 llstr(stats.write_requests,llbuff1),
553 llstr(stats.writes,llbuff2),
554 llstr(stats.read_requests,llbuff3),
555 llstr(stats.reads,llbuff4));
556 }
557 return 0;
558}
559C_MODE_END
560
561
562void mysql_print_status()
563{
564 char current_dir[FN_REFLEN];
565 STATUS_VAR tmp;
566 uint count;
567
568 count= calc_sum_of_all_status(&tmp);
569 printf("\nStatus information:\n\n");
570 (void) my_getwd(current_dir, sizeof(current_dir),MYF(0));
571 printf("Current dir: %s\n", current_dir);
572 printf("Running threads: %d Cached threads: %lu Stack size: %ld\n",
573 count, cached_thread_count,
574 (long) my_thread_stack_size);
575#ifdef EXTRA_DEBUG
576 thr_print_locks(); // Write some debug info
577 print_cached_tables();
578#endif
579 /* Print key cache status */
580 puts("\nKey caches:");
581 process_key_caches(print_key_cache_status, 0);
582 printf("\nhandler status:\n\
583read_key: %10lu\n\
584read_next: %10lu\n\
585read_rnd %10lu\n\
586read_first: %10lu\n\
587write: %10lu\n\
588delete %10lu\n\
589update: %10lu\n",
590 tmp.ha_read_key_count,
591 tmp.ha_read_next_count,
592 tmp.ha_read_rnd_count,
593 tmp.ha_read_first_count,
594 tmp.ha_write_count,
595 tmp.ha_delete_count,
596 tmp.ha_update_count);
597 printf("\nTable status:\n\
598Opened tables: %10lu\n\
599Open tables: %10lu\n\
600Open files: %10lu\n\
601Open streams: %10lu\n",
602 tmp.opened_tables,
603 (ulong) tc_records(),
604 (ulong) my_file_opened,
605 (ulong) my_stream_opened);
606
607#ifndef DONT_USE_THR_ALARM
608 ALARM_INFO alarm_info;
609 thr_alarm_info(&alarm_info);
610 printf("\nAlarm status:\n\
611Active alarms: %u\n\
612Max used alarms: %u\n\
613Next alarm time: %lu\n",
614 alarm_info.active_alarms,
615 alarm_info.max_used_alarms,
616 (ulong)alarm_info.next_alarm_time);
617#endif
618 display_table_locks();
619#ifdef HAVE_MALLINFO
620 struct mallinfo info= mallinfo();
621 char llbuff[10][22];
622 printf("\nMemory status:\n\
623Non-mmapped space allocated from system: %s\n\
624Number of free chunks: %lu\n\
625Number of fastbin blocks: %lu\n\
626Number of mmapped regions: %lu\n\
627Space in mmapped regions: %s\n\
628Maximum total allocated space: %s\n\
629Space available in freed fastbin blocks: %s\n\
630Total allocated space: %s\n\
631Total free space: %s\n\
632Top-most, releasable space: %s\n\
633Estimated memory (with thread stack): %s\n\
634Global memory allocated by server: %s\n\
635Memory allocated by threads: %s\n",
636 llstr(info.arena, llbuff[0]),
637 (ulong) info.ordblks,
638 (ulong) info.smblks,
639 (ulong) info.hblks,
640 llstr(info.hblkhd, llbuff[1]),
641 llstr(info.usmblks, llbuff[2]),
642 llstr(info.fsmblks, llbuff[3]),
643 llstr(info.uordblks, llbuff[4]),
644 llstr(info.fordblks, llbuff[5]),
645 llstr(info.keepcost, llbuff[6]),
646 llstr((count + cached_thread_count)* my_thread_stack_size + info.hblkhd + info.arena, llbuff[7]),
647 llstr(tmp.global_memory_used, llbuff[8]),
648 llstr(tmp.local_memory_used, llbuff[9]));
649
650#endif
651
652#ifdef HAVE_EVENT_SCHEDULER
653 Events::dump_internal_status();
654#endif
655 puts("");
656 fflush(stdout);
657}
658