1 /* Copyright (c) 2000, 2016, 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 Street, Fifth Floor, Boston, MA  02110-1301, USA */
15 
16 
17 /**
18   @file
19 
20   @brief
21   logging of commands
22 
23   @todo
24     Abort logging when we get an error in reading or writing log files
25 */
26 
27 #include "my_global.h"                          /* NO_EMBEDDED_ACCESS_CHECKS */
28 #include "sql_priv.h"
29 #include "log.h"
30 #include "sql_base.h"                           // open_log_table
31 #include "sql_repl.h"
32 #include "sql_delete.h"                         // mysql_truncate
33 #include "sql_parse.h"                          // command_name
34 #include "sql_time.h"           // calc_time_from_sec, my_time_compare
35 #include "tztime.h"             // my_tz_OFFSET0, struct Time_zone
36 #include "sql_acl.h"            // SUPER_ACL
37 #include "log_event.h"          // Query_log_event
38 #include "rpl_filter.h"
39 #include "rpl_rli.h"
40 #include "sql_audit.h"
41 
42 #include "sql_show.h"
43 #include <my_dir.h>
44 #include <stdarg.h>
45 #include <m_ctype.h>				// For test_if_number
46 
47 #ifdef _WIN32
48 #include "message.h"
49 #endif
50 
51 #include "sql_plugin.h"
52 #include "rpl_handler.h"
53 #include "debug_sync.h"
54 /* max size of the log message */
55 #define MAX_LOG_BUFFER_SIZE 1024
56 #define MAX_TIME_SIZE 32
57 #define MY_OFF_T_UNDEF (~(my_off_t)0UL)
58 
59 #define FLAGSTR(V,F) ((V)&(F)?#F" ":"")
60 
61 LOGGER logger;
62 
63 MYSQL_BIN_LOG mysql_bin_log(&sync_binlog_period);
64 
65 static bool test_if_number(const char *str,
66 			   ulong *res, bool allow_wildcards);
67 static int binlog_init(void *p);
68 static int binlog_close_connection(handlerton *hton, THD *thd);
69 static int binlog_savepoint_set(handlerton *hton, THD *thd, void *sv);
70 static int binlog_savepoint_rollback(handlerton *hton, THD *thd, void *sv);
71 static int binlog_commit(handlerton *hton, THD *thd, bool all);
72 static int binlog_rollback(handlerton *hton, THD *thd, bool all);
73 static int binlog_prepare(handlerton *hton, THD *thd, bool all);
74 
75 /**
76    purge logs, master and slave sides both, related error code
77    convertor.
78    Called from @c purge_error_message(), @c MYSQL_BIN_LOG::reset_logs()
79 
80    @param  res  an internal to purging routines error code
81 
82    @return the user level error code ER_*
83 */
purge_log_get_error_code(int res)84 uint purge_log_get_error_code(int res)
85 {
86   uint errcode= 0;
87 
88   switch (res)  {
89   case 0: break;
90   case LOG_INFO_EOF:	errcode= ER_UNKNOWN_TARGET_BINLOG; break;
91   case LOG_INFO_IO:	errcode= ER_IO_ERR_LOG_INDEX_READ; break;
92   case LOG_INFO_INVALID:errcode= ER_BINLOG_PURGE_PROHIBITED; break;
93   case LOG_INFO_SEEK:	errcode= ER_FSEEK_FAIL; break;
94   case LOG_INFO_MEM:	errcode= ER_OUT_OF_RESOURCES; break;
95   case LOG_INFO_FATAL:	errcode= ER_BINLOG_PURGE_FATAL_ERR; break;
96   case LOG_INFO_IN_USE: errcode= ER_LOG_IN_USE; break;
97   case LOG_INFO_EMFILE: errcode= ER_BINLOG_PURGE_EMFILE; break;
98   default:		errcode= ER_LOG_PURGE_UNKNOWN_ERR; break;
99   }
100 
101   return errcode;
102 }
103 
104 /**
105   Silence all errors and warnings reported when performing a write
106   to a log table.
107   Errors and warnings are not reported to the client or SQL exception
108   handlers, so that the presence of logging does not interfere and affect
109   the logic of an application.
110 */
111 class Silence_log_table_errors : public Internal_error_handler
112 {
113   char m_message[MYSQL_ERRMSG_SIZE];
114 public:
Silence_log_table_errors()115   Silence_log_table_errors()
116   {
117     m_message[0]= '\0';
118   }
119 
~Silence_log_table_errors()120   virtual ~Silence_log_table_errors() {}
121 
122   virtual bool handle_condition(THD *thd,
123                                 uint sql_errno,
124                                 const char* sql_state,
125                                 MYSQL_ERROR::enum_warning_level level,
126                                 const char* msg,
127                                 MYSQL_ERROR ** cond_hdl);
message() const128   const char *message() const { return m_message; }
129 };
130 
131 bool
handle_condition(THD *,uint,const char *,MYSQL_ERROR::enum_warning_level,const char * msg,MYSQL_ERROR ** cond_hdl)132 Silence_log_table_errors::handle_condition(THD *,
133                                            uint,
134                                            const char*,
135                                            MYSQL_ERROR::enum_warning_level,
136                                            const char* msg,
137                                            MYSQL_ERROR ** cond_hdl)
138 {
139   *cond_hdl= NULL;
140   strmake(m_message, msg, sizeof(m_message)-1);
141   return TRUE;
142 }
143 
144 sql_print_message_func sql_print_message_handlers[3] =
145 {
146   sql_print_information,
147   sql_print_warning,
148   sql_print_error
149 };
150 
151 /**
152   Create the name of the log specified.
153 
154   This method forms a new path + file name for the
155   log specified in @c name.
156 
157   @param[IN] buff    Location for building new string.
158   @param[IN] name    Name of the log file.
159   @param[IN] log_ext The extension for the log (e.g. .log).
160 
161   @returns Pointer to new string containing the name.
162 */
make_log_name(char * buff,const char * name,const char * log_ext)163 char *make_log_name(char *buff, const char *name, const char* log_ext)
164 {
165   strmake(buff, name, FN_REFLEN-5);
166   return fn_format(buff, buff, mysql_real_data_home, log_ext,
167                    MYF(MY_UNPACK_FILENAME|MY_REPLACE_EXT));
168 }
169 
170 /*
171   Helper class to hold a mutex for the duration of the
172   block.
173 
174   Eliminates the need for explicit unlocking of mutexes on, e.g.,
175   error returns.  On passing a null pointer, the sentry will not do
176   anything.
177  */
178 class Mutex_sentry
179 {
180 public:
Mutex_sentry(mysql_mutex_t * mutex)181   Mutex_sentry(mysql_mutex_t *mutex)
182     : m_mutex(mutex)
183   {
184     if (m_mutex)
185       mysql_mutex_lock(mutex);
186   }
187 
~Mutex_sentry()188   ~Mutex_sentry()
189   {
190     if (m_mutex)
191       mysql_mutex_unlock(m_mutex);
192 #ifndef DBUG_OFF
193     m_mutex= 0;
194 #endif
195   }
196 
197 private:
198   mysql_mutex_t *m_mutex;
199 
200   // It's not allowed to copy this object in any way
201   Mutex_sentry(Mutex_sentry const&);
202   void operator=(Mutex_sentry const&);
203 };
204 
205 /*
206   Helper classes to store non-transactional and transactional data
207   before copying it to the binary log.
208 */
209 class binlog_cache_data
210 {
211 public:
binlog_cache_data()212   binlog_cache_data(): m_pending(0), before_stmt_pos(MY_OFF_T_UNDEF),
213   incident(FALSE), changes_to_non_trans_temp_table_flag(FALSE),
214   saved_max_binlog_cache_size(0), ptr_binlog_cache_use(0),
215   ptr_binlog_cache_disk_use(0)
216   { }
217 
~binlog_cache_data()218   ~binlog_cache_data()
219   {
220     DBUG_ASSERT(empty());
221     close_cached_file(&cache_log);
222   }
223 
empty() const224   bool empty() const
225   {
226     return pending() == NULL && my_b_tell(&cache_log) == 0;
227   }
228 
pending() const229   Rows_log_event *pending() const
230   {
231     return m_pending;
232   }
233 
set_pending(Rows_log_event * const pending)234   void set_pending(Rows_log_event *const pending)
235   {
236     m_pending= pending;
237   }
238 
set_incident(void)239   void set_incident(void)
240   {
241     incident= TRUE;
242   }
243 
has_incident(void)244   bool has_incident(void)
245   {
246     return(incident);
247   }
248 
set_changes_to_non_trans_temp_table()249   void set_changes_to_non_trans_temp_table()
250   {
251     changes_to_non_trans_temp_table_flag= TRUE;
252   }
253 
changes_to_non_trans_temp_table()254   bool changes_to_non_trans_temp_table()
255   {
256     return (changes_to_non_trans_temp_table_flag);
257   }
258 
reset()259   void reset()
260   {
261     compute_statistics();
262     truncate(0);
263     changes_to_non_trans_temp_table_flag= FALSE;
264     incident= FALSE;
265     before_stmt_pos= MY_OFF_T_UNDEF;
266     /*
267       The truncate function calls reinit_io_cache that calls my_b_flush_io_cache
268       which may increase disk_writes. This breaks the disk_writes use by the
269       binary log which aims to compute the ratio between in-memory cache usage
270       and disk cache usage. To avoid this undesirable behavior, we reset the
271       variable after truncating the cache.
272     */
273     cache_log.disk_writes= 0;
274     DBUG_ASSERT(empty());
275   }
276 
get_byte_position() const277   my_off_t get_byte_position() const
278   {
279     return my_b_tell(&cache_log);
280   }
281 
get_prev_position()282   my_off_t get_prev_position()
283   {
284      return(before_stmt_pos);
285   }
286 
set_prev_position(my_off_t pos)287   void set_prev_position(my_off_t pos)
288   {
289      before_stmt_pos= pos;
290   }
291 
restore_prev_position()292   void restore_prev_position()
293   {
294     truncate(before_stmt_pos);
295   }
296 
restore_savepoint(my_off_t pos)297   void restore_savepoint(my_off_t pos)
298   {
299     truncate(pos);
300     if (pos < before_stmt_pos)
301       before_stmt_pos= MY_OFF_T_UNDEF;
302   }
303 
set_binlog_cache_info(my_off_t param_max_binlog_cache_size,ulong * param_ptr_binlog_cache_use,ulong * param_ptr_binlog_cache_disk_use)304   void set_binlog_cache_info(my_off_t param_max_binlog_cache_size,
305                              ulong *param_ptr_binlog_cache_use,
306                              ulong *param_ptr_binlog_cache_disk_use)
307   {
308     /*
309       The assertions guarantee that the set_binlog_cache_info is
310       called just once and information passed as parameters are
311       never zero.
312 
313       This is done while calling the constructor binlog_cache_mngr.
314       We cannot set informaton in the constructor binlog_cache_data
315       because the space for binlog_cache_mngr is allocated through
316       a placement new.
317 
318       In the future, we can refactor this and change it to avoid
319       the set_binlog_info.
320     */
321     DBUG_ASSERT(saved_max_binlog_cache_size == 0 &&
322                 param_max_binlog_cache_size != 0 &&
323                 ptr_binlog_cache_use == 0 &&
324                 param_ptr_binlog_cache_use != 0 &&
325                 ptr_binlog_cache_disk_use == 0 &&
326                 param_ptr_binlog_cache_disk_use != 0);
327 
328     saved_max_binlog_cache_size= param_max_binlog_cache_size;
329     ptr_binlog_cache_use= param_ptr_binlog_cache_use;
330     ptr_binlog_cache_disk_use= param_ptr_binlog_cache_disk_use;
331     cache_log.end_of_file= saved_max_binlog_cache_size;
332   }
333 
334   /*
335     Cache to store data before copying it to the binary log.
336   */
337   IO_CACHE cache_log;
338 
339 private:
340   /*
341     Pending binrows event. This event is the event where the rows are currently
342     written.
343    */
344   Rows_log_event *m_pending;
345 
346   /*
347     Binlog position before the start of the current statement.
348   */
349   my_off_t before_stmt_pos;
350 
351   /*
352     This indicates that some events did not get into the cache and most likely
353     it is corrupted.
354   */
355   bool incident;
356 
357   /*
358     This flag indicates if the cache has changes to temporary tables.
359     @TODO This a temporary fix and should be removed after BUG#54562.
360   */
361   bool changes_to_non_trans_temp_table_flag;
362 
363   /**
364     This function computes binlog cache and disk usage.
365   */
compute_statistics()366   void compute_statistics()
367   {
368     if (!empty())
369     {
370       statistic_increment(*ptr_binlog_cache_use, &LOCK_status);
371       if (cache_log.disk_writes != 0)
372         statistic_increment(*ptr_binlog_cache_disk_use, &LOCK_status);
373     }
374   }
375 
376   /*
377     Stores the values of maximum size of the cache allowed when this cache
378     is configured. This corresponds to either
379       . max_binlog_cache_size or max_binlog_stmt_cache_size.
380   */
381   my_off_t saved_max_binlog_cache_size;
382 
383   /*
384     Stores a pointer to the status variable that keeps track of the in-memory
385     cache usage. This corresponds to either
386       . binlog_cache_use or binlog_stmt_cache_use.
387   */
388   ulong *ptr_binlog_cache_use;
389 
390   /*
391     Stores a pointer to the status variable that keeps track of the disk
392     cache usage. This corresponds to either
393       . binlog_cache_disk_use or binlog_stmt_cache_disk_use.
394   */
395   ulong *ptr_binlog_cache_disk_use;
396 
397   /*
398     It truncates the cache to a certain position. This includes deleting the
399     pending event.
400    */
truncate(my_off_t pos)401   void truncate(my_off_t pos)
402   {
403     DBUG_PRINT("info", ("truncating to position %lu", (ulong) pos));
404     if (pending())
405     {
406       delete pending();
407       set_pending(0);
408     }
409     reinit_io_cache(&cache_log, WRITE_CACHE, pos, 0, 0);
410     cache_log.end_of_file= saved_max_binlog_cache_size;
411   }
412 
413   binlog_cache_data& operator=(const binlog_cache_data& info);
414   binlog_cache_data(const binlog_cache_data& info);
415 };
416 
417 class binlog_cache_mngr {
418 public:
binlog_cache_mngr(my_off_t param_max_binlog_stmt_cache_size,my_off_t param_max_binlog_cache_size,ulong * param_ptr_binlog_stmt_cache_use,ulong * param_ptr_binlog_stmt_cache_disk_use,ulong * param_ptr_binlog_cache_use,ulong * param_ptr_binlog_cache_disk_use)419   binlog_cache_mngr(my_off_t param_max_binlog_stmt_cache_size,
420                     my_off_t param_max_binlog_cache_size,
421                     ulong *param_ptr_binlog_stmt_cache_use,
422                     ulong *param_ptr_binlog_stmt_cache_disk_use,
423                     ulong *param_ptr_binlog_cache_use,
424                     ulong *param_ptr_binlog_cache_disk_use)
425   {
426      stmt_cache.set_binlog_cache_info(param_max_binlog_stmt_cache_size,
427                                       param_ptr_binlog_stmt_cache_use,
428                                       param_ptr_binlog_stmt_cache_disk_use);
429      trx_cache.set_binlog_cache_info(param_max_binlog_cache_size,
430                                      param_ptr_binlog_cache_use,
431                                      param_ptr_binlog_cache_disk_use);
432   }
433 
reset_cache(binlog_cache_data * cache_data)434   void reset_cache(binlog_cache_data* cache_data)
435   {
436     cache_data->reset();
437   }
438 
get_binlog_cache_data(bool is_transactional)439   binlog_cache_data* get_binlog_cache_data(bool is_transactional)
440   {
441     return (is_transactional ? &trx_cache : &stmt_cache);
442   }
443 
get_binlog_cache_log(bool is_transactional)444   IO_CACHE* get_binlog_cache_log(bool is_transactional)
445   {
446     return (is_transactional ? &trx_cache.cache_log : &stmt_cache.cache_log);
447   }
448 
449   binlog_cache_data stmt_cache;
450 
451   binlog_cache_data trx_cache;
452 
453 private:
454 
455   binlog_cache_mngr& operator=(const binlog_cache_mngr& info);
456   binlog_cache_mngr(const binlog_cache_mngr& info);
457 };
458 
459 handlerton *binlog_hton;
460 
is_log_table_enabled(uint log_table_type)461 bool LOGGER::is_log_table_enabled(uint log_table_type)
462 {
463   switch (log_table_type) {
464   case QUERY_LOG_SLOW:
465     return (table_log_handler != NULL) && opt_slow_log;
466   case QUERY_LOG_GENERAL:
467     return (table_log_handler != NULL) && opt_log ;
468   default:
469     DBUG_ASSERT(0);
470     return FALSE;                             /* make compiler happy */
471   }
472 }
473 
474 
475 /* Check if a given table is opened log table */
check_if_log_table(size_t db_len,const char * db,size_t table_name_len,const char * table_name,bool check_if_opened)476 int check_if_log_table(size_t db_len, const char *db, size_t table_name_len,
477                        const char *table_name, bool check_if_opened)
478 {
479   if (db_len == 5 &&
480       !(lower_case_table_names ?
481         my_strcasecmp(system_charset_info, db, "mysql") :
482         strcmp(db, "mysql")))
483   {
484     if (table_name_len == 11 && !(lower_case_table_names ?
485                                   my_strcasecmp(system_charset_info,
486                                                 table_name, "general_log") :
487                                   strcmp(table_name, "general_log")))
488     {
489       if (!check_if_opened || logger.is_log_table_enabled(QUERY_LOG_GENERAL))
490         return QUERY_LOG_GENERAL;
491       return 0;
492     }
493 
494     if (table_name_len == 8 && !(lower_case_table_names ?
495       my_strcasecmp(system_charset_info, table_name, "slow_log") :
496       strcmp(table_name, "slow_log")))
497     {
498       if (!check_if_opened || logger.is_log_table_enabled(QUERY_LOG_SLOW))
499         return QUERY_LOG_SLOW;
500       return 0;
501     }
502   }
503   return 0;
504 }
505 
506 
Log_to_csv_event_handler()507 Log_to_csv_event_handler::Log_to_csv_event_handler()
508 {
509 }
510 
511 
~Log_to_csv_event_handler()512 Log_to_csv_event_handler::~Log_to_csv_event_handler()
513 {
514 }
515 
516 
cleanup()517 void Log_to_csv_event_handler::cleanup()
518 {
519   logger.is_log_tables_initialized= FALSE;
520 }
521 
522 /* log event handlers */
523 
524 /**
525   Log command to the general log table
526 
527   Log given command to the general log table.
528 
529   @param  event_time        command start timestamp
530   @param  user_host         the pointer to the string with user@host info
531   @param  user_host_len     length of the user_host string. this is computed
532                             once and passed to all general log event handlers
533   @param  thread_id         Id of the thread, issued a query
534   @param  command_type      the type of the command being logged
535   @param  command_type_len  the length of the string above
536   @param  sql_text          the very text of the query being executed
537   @param  sql_text_len      the length of sql_text string
538 
539 
540   @return This function attempts to never call my_error(). This is
541   necessary, because general logging happens already after a statement
542   status has been sent to the client, so the client can not see the
543   error anyway. Besides, the error is not related to the statement
544   being executed and is internal, and thus should be handled
545   internally (@todo: how?).
546   If a write to the table has failed, the function attempts to
547   write to a short error message to the file. The failure is also
548   indicated in the return value.
549 
550   @retval  FALSE   OK
551   @retval  TRUE    error occured
552 */
553 
554 bool Log_to_csv_event_handler::
log_general(THD * thd,time_t event_time,const char * user_host,uint user_host_len,int thread_id,const char * command_type,uint command_type_len,const char * sql_text,uint sql_text_len,CHARSET_INFO * client_cs)555   log_general(THD *thd, time_t event_time, const char *user_host,
556               uint user_host_len, int thread_id,
557               const char *command_type, uint command_type_len,
558               const char *sql_text, uint sql_text_len,
559               CHARSET_INFO *client_cs)
560 {
561   TABLE_LIST table_list;
562   TABLE *table;
563   bool result= TRUE;
564   bool need_close= FALSE;
565   bool need_pop= FALSE;
566   bool need_rnd_end= FALSE;
567   uint field_index;
568   Silence_log_table_errors error_handler;
569   Open_tables_backup open_tables_backup;
570   ulonglong save_thd_options;
571   bool save_time_zone_used;
572 
573   /*
574     CSV uses TIME_to_timestamp() internally if table needs to be repaired
575     which will set thd->time_zone_used
576   */
577   save_time_zone_used= thd->time_zone_used;
578 
579   save_thd_options= thd->variables.option_bits;
580   thd->variables.option_bits&= ~OPTION_BIN_LOG;
581 
582   table_list.init_one_table(MYSQL_SCHEMA_NAME.str, MYSQL_SCHEMA_NAME.length,
583                             GENERAL_LOG_NAME.str, GENERAL_LOG_NAME.length,
584                             GENERAL_LOG_NAME.str,
585                             TL_WRITE_CONCURRENT_INSERT);
586 
587   /*
588     1) open_log_table generates an error of the
589     table can not be opened or is corrupted.
590     2) "INSERT INTO general_log" can generate warning sometimes.
591 
592     Suppress these warnings and errors, they can't be dealt with
593     properly anyway.
594 
595     QQ: this problem needs to be studied in more detail.
596     Comment this 2 lines and run "cast.test" to see what's happening.
597   */
598   thd->push_internal_handler(& error_handler);
599   need_pop= TRUE;
600 
601   if (!(table= open_log_table(thd, &table_list, &open_tables_backup)))
602     goto err;
603 
604   need_close= TRUE;
605 
606   if (table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) ||
607       table->file->ha_rnd_init(0))
608     goto err;
609 
610   need_rnd_end= TRUE;
611 
612   /* Honor next number columns if present */
613   table->next_number_field= table->found_next_number_field;
614 
615   /*
616     NOTE: we do not call restore_record() here, as all fields are
617     filled by the Logger (=> no need to load default ones).
618   */
619 
620   /*
621     We do not set a value for table->field[0], as it will use
622     default value (which is CURRENT_TIMESTAMP).
623   */
624 
625   /* check that all columns exist */
626   if (table->s->fields < 6)
627     goto err;
628 
629   DBUG_ASSERT(table->field[0]->type() == MYSQL_TYPE_TIMESTAMP);
630 
631   ((Field_timestamp*) table->field[0])->store_timestamp((my_time_t)
632                                                         event_time);
633 
634   /* do a write */
635   if (table->field[1]->store(user_host, user_host_len, client_cs) ||
636       table->field[2]->store((longlong) thread_id, TRUE) ||
637       table->field[3]->store((longlong) server_id, TRUE) ||
638       table->field[4]->store(command_type, command_type_len, client_cs))
639     goto err;
640 
641   /*
642     A positive return value in store() means truncation.
643     Still logging a message in the log in this case.
644   */
645   table->field[5]->flags|= FIELDFLAG_HEX_ESCAPE;
646   if (table->field[5]->store(sql_text, sql_text_len, client_cs) < 0)
647     goto err;
648 
649   /* mark all fields as not null */
650   table->field[1]->set_notnull();
651   table->field[2]->set_notnull();
652   table->field[3]->set_notnull();
653   table->field[4]->set_notnull();
654   table->field[5]->set_notnull();
655 
656   /* Set any extra columns to their default values */
657   for (field_index= 6 ; field_index < table->s->fields ; field_index++)
658   {
659     table->field[field_index]->set_default();
660   }
661 
662   /* log table entries are not replicated */
663   if (table->file->ha_write_row(table->record[0]))
664     goto err;
665 
666   result= FALSE;
667 
668 err:
669   if (result && !thd->killed)
670     sql_print_error("Failed to write to mysql.general_log: %s",
671                     error_handler.message());
672 
673   if (need_rnd_end)
674   {
675     table->file->ha_rnd_end();
676     table->file->ha_release_auto_increment();
677   }
678   if (need_pop)
679     thd->pop_internal_handler();
680   if (need_close)
681     close_log_table(thd, &open_tables_backup);
682 
683   thd->variables.option_bits= save_thd_options;
684   thd->time_zone_used= save_time_zone_used;
685   return result;
686 }
687 
688 
689 /*
690   Log a query to the slow log table
691 
692   SYNOPSIS
693     log_slow()
694     thd               THD of the query
695     current_time      current timestamp
696     query_start_arg   command start timestamp
697     user_host         the pointer to the string with user@host info
698     user_host_len     length of the user_host string. this is computed once
699                       and passed to all general log event handlers
700     query_time        Amount of time the query took to execute (in microseconds)
701     lock_time         Amount of time the query was locked (in microseconds)
702     is_command        The flag, which determines, whether the sql_text is a
703                       query or an administrator command (these are treated
704                       differently by the old logging routines)
705     sql_text          the very text of the query or administrator command
706                       processed
707     sql_text_len      the length of sql_text string
708 
709   DESCRIPTION
710 
711    Log a query to the slow log table
712 
713   RETURN
714     FALSE - OK
715     TRUE - error occured
716 */
717 
718 bool Log_to_csv_event_handler::
log_slow(THD * thd,time_t current_time,time_t query_start_arg,const char * user_host,uint user_host_len,ulonglong query_utime,ulonglong lock_utime,bool is_command,const char * sql_text,uint sql_text_len)719   log_slow(THD *thd, time_t current_time, time_t query_start_arg,
720            const char *user_host, uint user_host_len,
721            ulonglong query_utime, ulonglong lock_utime, bool is_command,
722            const char *sql_text, uint sql_text_len)
723 {
724   TABLE_LIST table_list;
725   TABLE *table;
726   bool result= TRUE;
727   bool need_close= FALSE;
728   bool need_rnd_end= FALSE;
729   Silence_log_table_errors error_handler;
730   Open_tables_backup open_tables_backup;
731   CHARSET_INFO *client_cs= thd->variables.character_set_client;
732   bool save_time_zone_used;
733   DBUG_ENTER("Log_to_csv_event_handler::log_slow");
734 
735   thd->push_internal_handler(& error_handler);
736   /*
737     CSV uses TIME_to_timestamp() internally if table needs to be repaired
738     which will set thd->time_zone_used
739   */
740   save_time_zone_used= thd->time_zone_used;
741 
742   table_list.init_one_table(MYSQL_SCHEMA_NAME.str, MYSQL_SCHEMA_NAME.length,
743                             SLOW_LOG_NAME.str, SLOW_LOG_NAME.length,
744                             SLOW_LOG_NAME.str,
745                             TL_WRITE_CONCURRENT_INSERT);
746 
747   if (!(table= open_log_table(thd, &table_list, &open_tables_backup)))
748     goto err;
749 
750   need_close= TRUE;
751 
752   if (table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) ||
753       table->file->ha_rnd_init(0))
754     goto err;
755 
756   need_rnd_end= TRUE;
757 
758   /* Honor next number columns if present */
759   table->next_number_field= table->found_next_number_field;
760 
761   restore_record(table, s->default_values);    // Get empty record
762 
763   /* check that all columns exist */
764   if (table->s->fields < 11)
765     goto err;
766 
767   /* store the time and user values */
768   DBUG_ASSERT(table->field[0]->type() == MYSQL_TYPE_TIMESTAMP);
769   ((Field_timestamp*) table->field[0])->store_timestamp((my_time_t)
770                                                         current_time);
771   if (table->field[1]->store(user_host, user_host_len, client_cs))
772     goto err;
773 
774   if (query_start_arg)
775   {
776     longlong query_time= (longlong) (query_utime/1000000);
777     longlong lock_time=  (longlong) (lock_utime/1000000);
778     /*
779       A TIME field can not hold the full longlong range; query_time or
780       lock_time may be truncated without warning here, if greater than
781       839 hours (~35 days)
782     */
783     MYSQL_TIME t;
784     t.neg= 0;
785 
786     /* fill in query_time field */
787     calc_time_from_sec(&t, (long) min(query_time, (longlong) TIME_MAX_VALUE_SECONDS), 0);
788     if (table->field[2]->store_time(&t, MYSQL_TIMESTAMP_TIME))
789       goto err;
790     /* lock_time */
791     calc_time_from_sec(&t, (long) min(lock_time, (longlong) TIME_MAX_VALUE_SECONDS), 0);
792     if (table->field[3]->store_time(&t, MYSQL_TIMESTAMP_TIME))
793       goto err;
794     /* rows_sent */
795     if (table->field[4]->store((longlong) thd->sent_row_count, TRUE))
796       goto err;
797     /* rows_examined */
798     if (table->field[5]->store((longlong) thd->examined_row_count, TRUE))
799       goto err;
800   }
801   else
802   {
803     table->field[2]->set_null();
804     table->field[3]->set_null();
805     table->field[4]->set_null();
806     table->field[5]->set_null();
807   }
808   /* fill database field */
809   if (thd->db)
810   {
811     if (table->field[6]->store(thd->db, thd->db_length, client_cs))
812       goto err;
813     table->field[6]->set_notnull();
814   }
815 
816   if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
817   {
818     if (table->
819         field[7]->store((longlong)
820                         thd->first_successful_insert_id_in_prev_stmt_for_binlog,
821                         TRUE))
822       goto err;
823     table->field[7]->set_notnull();
824   }
825 
826   /*
827     Set value if we do an insert on autoincrement column. Note that for
828     some engines (those for which get_auto_increment() does not leave a
829     table lock until the statement ends), this is just the first value and
830     the next ones used may not be contiguous to it.
831   */
832   if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
833   {
834     if (table->
835         field[8]->store((longlong)
836           thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(), TRUE))
837       goto err;
838     table->field[8]->set_notnull();
839   }
840 
841   if (table->field[9]->store((longlong) server_id, TRUE))
842     goto err;
843   table->field[9]->set_notnull();
844 
845   /*
846     Column sql_text.
847     A positive return value in store() means truncation.
848     Still logging a message in the log in this case.
849   */
850   if (table->field[10]->store(sql_text, sql_text_len, client_cs) < 0)
851     goto err;
852 
853   /* log table entries are not replicated */
854   if (table->file->ha_write_row(table->record[0]))
855     goto err;
856 
857   result= FALSE;
858 
859 err:
860   thd->pop_internal_handler();
861 
862   if (result && !thd->killed)
863     sql_print_error("Failed to write to mysql.slow_log: %s",
864                     error_handler.message());
865 
866   if (need_rnd_end)
867   {
868     table->file->ha_rnd_end();
869     table->file->ha_release_auto_increment();
870   }
871   if (need_close)
872     close_log_table(thd, &open_tables_backup);
873   thd->time_zone_used= save_time_zone_used;
874   DBUG_RETURN(result);
875 }
876 
877 int Log_to_csv_event_handler::
activate_log(THD * thd,uint log_table_type)878   activate_log(THD *thd, uint log_table_type)
879 {
880   TABLE_LIST table_list;
881   TABLE *table;
882   LEX_STRING *UNINIT_VAR(log_name);
883   int result;
884   Open_tables_backup open_tables_backup;
885 
886   DBUG_ENTER("Log_to_csv_event_handler::activate_log");
887 
888   if (log_table_type == QUERY_LOG_GENERAL)
889   {
890     log_name= &GENERAL_LOG_NAME;
891   }
892   else
893   {
894     DBUG_ASSERT(log_table_type == QUERY_LOG_SLOW);
895 
896     log_name= &SLOW_LOG_NAME;
897   }
898   table_list.init_one_table(MYSQL_SCHEMA_NAME.str, MYSQL_SCHEMA_NAME.length,
899                             log_name->str, log_name->length, log_name->str,
900                             TL_WRITE_CONCURRENT_INSERT);
901 
902   table= open_log_table(thd, &table_list, &open_tables_backup);
903   if (table)
904   {
905     result= 0;
906     close_log_table(thd, &open_tables_backup);
907   }
908   else
909     result= 1;
910 
911   DBUG_RETURN(result);
912 }
913 
914 bool Log_to_csv_event_handler::
log_error(enum loglevel level,const char * format,va_list args)915   log_error(enum loglevel level, const char *format, va_list args)
916 {
917   /* No log table is implemented */
918   DBUG_ASSERT(0);
919   return FALSE;
920 }
921 
922 bool Log_to_file_event_handler::
log_error(enum loglevel level,const char * format,va_list args)923   log_error(enum loglevel level, const char *format,
924             va_list args)
925 {
926   return vprint_msg_to_log(level, format, args);
927 }
928 
init_pthread_objects()929 void Log_to_file_event_handler::init_pthread_objects()
930 {
931   mysql_log.init_pthread_objects();
932   mysql_slow_log.init_pthread_objects();
933 }
934 
935 
936 /** Wrapper around MYSQL_LOG::write() for slow log. */
937 
938 bool Log_to_file_event_handler::
log_slow(THD * thd,time_t current_time,time_t query_start_arg,const char * user_host,uint user_host_len,ulonglong query_utime,ulonglong lock_utime,bool is_command,const char * sql_text,uint sql_text_len)939   log_slow(THD *thd, time_t current_time, time_t query_start_arg,
940            const char *user_host, uint user_host_len,
941            ulonglong query_utime, ulonglong lock_utime, bool is_command,
942            const char *sql_text, uint sql_text_len)
943 {
944   Silence_log_table_errors error_handler;
945   thd->push_internal_handler(&error_handler);
946   bool retval= mysql_slow_log.write(thd, current_time, query_start_arg,
947                                     user_host, user_host_len,
948                                     query_utime, lock_utime, is_command,
949                                     sql_text, sql_text_len);
950   thd->pop_internal_handler();
951   return retval;
952 }
953 
954 
955 /**
956    Wrapper around MYSQL_LOG::write() for general log. We need it since we
957    want all log event handlers to have the same signature.
958 */
959 
960 bool Log_to_file_event_handler::
log_general(THD * thd,time_t event_time,const char * user_host,uint user_host_len,int thread_id,const char * command_type,uint command_type_len,const char * sql_text,uint sql_text_len,CHARSET_INFO * client_cs)961   log_general(THD *thd, time_t event_time, const char *user_host,
962               uint user_host_len, int thread_id,
963               const char *command_type, uint command_type_len,
964               const char *sql_text, uint sql_text_len,
965               CHARSET_INFO *client_cs)
966 {
967   Silence_log_table_errors error_handler;
968   thd->push_internal_handler(&error_handler);
969   bool retval= mysql_log.write(event_time, user_host, user_host_len,
970                                thread_id, command_type, command_type_len,
971                                sql_text, sql_text_len);
972   thd->pop_internal_handler();
973   return retval;
974 }
975 
976 
init()977 bool Log_to_file_event_handler::init()
978 {
979   if (!is_initialized)
980   {
981     if (opt_slow_log)
982       mysql_slow_log.open_slow_log(opt_slow_logname);
983 
984     if (opt_log)
985       mysql_log.open_query_log(opt_logname);
986 
987     is_initialized= TRUE;
988   }
989 
990   return FALSE;
991 }
992 
993 
cleanup()994 void Log_to_file_event_handler::cleanup()
995 {
996   mysql_log.cleanup();
997   mysql_slow_log.cleanup();
998 }
999 
flush()1000 void Log_to_file_event_handler::flush()
1001 {
1002   /* reopen log files */
1003   if (opt_log)
1004     mysql_log.reopen_file();
1005   if (opt_slow_log)
1006     mysql_slow_log.reopen_file();
1007 }
1008 
1009 /*
1010   Log error with all enabled log event handlers
1011 
1012   SYNOPSIS
1013     error_log_print()
1014 
1015     level             The level of the error significance: NOTE,
1016                       WARNING or ERROR.
1017     format            format string for the error message
1018     args              list of arguments for the format string
1019 
1020   RETURN
1021     FALSE - OK
1022     TRUE - error occured
1023 */
1024 
error_log_print(enum loglevel level,const char * format,va_list args)1025 bool LOGGER::error_log_print(enum loglevel level, const char *format,
1026                              va_list args)
1027 {
1028   bool error= FALSE;
1029   Log_event_handler **current_handler;
1030 
1031   /* currently we don't need locking here as there is no error_log table */
1032   for (current_handler= error_log_handler_list ; *current_handler ;)
1033     error= (*current_handler++)->log_error(level, format, args) || error;
1034 
1035   return error;
1036 }
1037 
1038 
cleanup_base()1039 void LOGGER::cleanup_base()
1040 {
1041   DBUG_ASSERT(inited == 1);
1042   mysql_rwlock_destroy(&LOCK_logger);
1043   if (table_log_handler)
1044   {
1045     table_log_handler->cleanup();
1046     delete table_log_handler;
1047     table_log_handler= NULL;
1048   }
1049   if (file_log_handler)
1050     file_log_handler->cleanup();
1051 }
1052 
1053 
cleanup_end()1054 void LOGGER::cleanup_end()
1055 {
1056   DBUG_ASSERT(inited == 1);
1057   if (file_log_handler)
1058   {
1059     delete file_log_handler;
1060     file_log_handler=NULL;
1061   }
1062   inited= 0;
1063 }
1064 
1065 
1066 /**
1067   Perform basic log initialization: create file-based log handler and
1068   init error log.
1069 */
init_base()1070 void LOGGER::init_base()
1071 {
1072   DBUG_ASSERT(inited == 0);
1073   inited= 1;
1074 
1075   /*
1076     Here we create file log handler. We don't do it for the table log handler
1077     here as it cannot be created so early. The reason is THD initialization,
1078     which depends on the system variables (parsed later).
1079   */
1080   if (!file_log_handler)
1081     file_log_handler= new Log_to_file_event_handler;
1082 
1083   /* by default we use traditional error log */
1084   init_error_log(LOG_FILE);
1085 
1086   file_log_handler->init_pthread_objects();
1087   mysql_rwlock_init(key_rwlock_LOCK_logger, &LOCK_logger);
1088 }
1089 
1090 
init_log_tables()1091 void LOGGER::init_log_tables()
1092 {
1093   if (!table_log_handler)
1094     table_log_handler= new Log_to_csv_event_handler;
1095 
1096   if (!is_log_tables_initialized &&
1097       !table_log_handler->init() && !file_log_handler->init())
1098     is_log_tables_initialized= TRUE;
1099 }
1100 
1101 
flush_logs(THD * thd)1102 bool LOGGER::flush_logs(THD *thd)
1103 {
1104   int rc= 0;
1105 
1106   /*
1107     Now we lock logger, as nobody should be able to use logging routines while
1108     log tables are closed
1109   */
1110   logger.lock_exclusive();
1111 
1112   /* reopen log files */
1113   file_log_handler->flush();
1114 
1115   /* end of log flush */
1116   logger.unlock();
1117   return rc;
1118 }
1119 
1120 
1121 /**
1122   Close and reopen the slow log (with locks).
1123 
1124   @returns FALSE.
1125 */
flush_slow_log()1126 bool LOGGER::flush_slow_log()
1127 {
1128   /*
1129     Now we lock logger, as nobody should be able to use logging routines while
1130     log tables are closed
1131   */
1132   logger.lock_exclusive();
1133 
1134   /* Reopen slow log file */
1135   if (opt_slow_log)
1136     file_log_handler->get_mysql_slow_log()->reopen_file();
1137 
1138   /* End of log flush */
1139   logger.unlock();
1140 
1141   return 0;
1142 }
1143 
1144 
1145 /**
1146   Close and reopen the general log (with locks).
1147 
1148   @returns FALSE.
1149 */
flush_general_log()1150 bool LOGGER::flush_general_log()
1151 {
1152   /*
1153     Now we lock logger, as nobody should be able to use logging routines while
1154     log tables are closed
1155   */
1156   logger.lock_exclusive();
1157 
1158   /* Reopen general log file */
1159   if (opt_log)
1160     file_log_handler->get_mysql_log()->reopen_file();
1161 
1162   /* End of log flush */
1163   logger.unlock();
1164 
1165   return 0;
1166 }
1167 
1168 
1169 /*
1170   Log slow query with all enabled log event handlers
1171 
1172   SYNOPSIS
1173     slow_log_print()
1174 
1175     thd                 THD of the query being logged
1176     query               The query being logged
1177     query_length        The length of the query string
1178     current_utime       Current time in microseconds (from undefined start)
1179 
1180   RETURN
1181     FALSE   OK
1182     TRUE    error occured
1183 */
1184 
slow_log_print(THD * thd,const char * query,uint query_length,ulonglong current_utime)1185 bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length,
1186                             ulonglong current_utime)
1187 
1188 {
1189   bool error= FALSE;
1190   Log_event_handler **current_handler;
1191   bool is_command= FALSE;
1192   char user_host_buff[MAX_USER_HOST_SIZE + 1];
1193   Security_context *sctx= thd->security_ctx;
1194   uint user_host_len= 0;
1195   ulonglong query_utime, lock_utime;
1196 
1197   DBUG_ASSERT(thd->enable_slow_log);
1198   /*
1199     Print the message to the buffer if we have slow log enabled
1200   */
1201 
1202   if (*slow_log_handler_list)
1203   {
1204     time_t current_time;
1205 
1206     /* do not log slow queries from replication threads */
1207     if (thd->slave_thread && !opt_log_slow_slave_statements)
1208       return 0;
1209 
1210     lock_shared();
1211     if (!opt_slow_log)
1212     {
1213       unlock();
1214       return 0;
1215     }
1216 
1217     /* fill in user_host value: the format is "%s[%s] @ %s [%s]" */
1218     user_host_len= (strxnmov(user_host_buff, MAX_USER_HOST_SIZE,
1219                              sctx->priv_user ? sctx->priv_user : "", "[",
1220                              sctx->user ? sctx->user : "", "] @ ",
1221                              sctx->get_host()->length() ?
1222                              sctx->get_host()->ptr() : "", " [",
1223                              sctx->get_ip()->length() ? sctx->get_ip()->ptr() :
1224                              "", "]", NullS) - user_host_buff);
1225 
1226 
1227     current_time= my_time_possible_from_micro(current_utime);
1228     if (thd->start_utime)
1229     {
1230       query_utime= (current_utime - thd->start_utime);
1231       lock_utime=  (thd->utime_after_lock - thd->start_utime);
1232     }
1233     else
1234     {
1235       query_utime= lock_utime= 0;
1236     }
1237 
1238     if (!query)
1239     {
1240       is_command= TRUE;
1241       query= command_name[thd->command].str;
1242       query_length= command_name[thd->command].length;
1243     }
1244 
1245     for (current_handler= slow_log_handler_list; *current_handler ;)
1246       error= (*current_handler++)->log_slow(thd, current_time, thd->start_time,
1247                                             user_host_buff, user_host_len,
1248                                             query_utime, lock_utime, is_command,
1249                                             query, query_length) || error;
1250 
1251     unlock();
1252   }
1253   return error;
1254 }
1255 
general_log_write(THD * thd,enum enum_server_command command,const char * query,uint query_length)1256 bool LOGGER::general_log_write(THD *thd, enum enum_server_command command,
1257                                const char *query, uint query_length)
1258 {
1259   bool error= FALSE;
1260   Log_event_handler **current_handler= general_log_handler_list;
1261   char user_host_buff[MAX_USER_HOST_SIZE + 1];
1262   uint user_host_len= 0;
1263   time_t current_time;
1264 
1265   DBUG_ASSERT(thd);
1266 
1267   lock_shared();
1268   if (!opt_log)
1269   {
1270     unlock();
1271     return 0;
1272   }
1273   user_host_len= make_user_name(thd, user_host_buff);
1274 
1275   current_time= my_time(0);
1276 
1277   mysql_audit_general_log(thd, current_time,
1278                           user_host_buff, user_host_len,
1279                           command_name[(uint) command].str,
1280                           command_name[(uint) command].length,
1281                           query, query_length);
1282 
1283   while (*current_handler)
1284     error|= (*current_handler++)->
1285       log_general(thd, current_time, user_host_buff,
1286                   user_host_len, thd->thread_id,
1287                   command_name[(uint) command].str,
1288                   command_name[(uint) command].length,
1289                   query, query_length,
1290                   thd->variables.character_set_client) || error;
1291   unlock();
1292 
1293   return error;
1294 }
1295 
general_log_print(THD * thd,enum enum_server_command command,const char * format,va_list args)1296 bool LOGGER::general_log_print(THD *thd, enum enum_server_command command,
1297                                const char *format, va_list args)
1298 {
1299   uint message_buff_len= 0;
1300   char message_buff[MAX_LOG_BUFFER_SIZE];
1301 
1302   /* prepare message */
1303   if (format)
1304     message_buff_len= my_vsnprintf(message_buff, sizeof(message_buff),
1305                                    format, args);
1306   else
1307     message_buff[0]= '\0';
1308 
1309   return general_log_write(thd, command, message_buff, message_buff_len);
1310 }
1311 
init_error_log(uint error_log_printer)1312 void LOGGER::init_error_log(uint error_log_printer)
1313 {
1314   if (error_log_printer & LOG_NONE)
1315   {
1316     error_log_handler_list[0]= 0;
1317     return;
1318   }
1319 
1320   switch (error_log_printer) {
1321   case LOG_FILE:
1322     error_log_handler_list[0]= file_log_handler;
1323     error_log_handler_list[1]= 0;
1324     break;
1325     /* these two are disabled for now */
1326   case LOG_TABLE:
1327     DBUG_ASSERT(0);
1328     break;
1329   case LOG_TABLE|LOG_FILE:
1330     DBUG_ASSERT(0);
1331     break;
1332   }
1333 }
1334 
init_slow_log(uint slow_log_printer)1335 void LOGGER::init_slow_log(uint slow_log_printer)
1336 {
1337   if (slow_log_printer & LOG_NONE)
1338   {
1339     slow_log_handler_list[0]= 0;
1340     return;
1341   }
1342 
1343   switch (slow_log_printer) {
1344   case LOG_FILE:
1345     slow_log_handler_list[0]= file_log_handler;
1346     slow_log_handler_list[1]= 0;
1347     break;
1348   case LOG_TABLE:
1349     slow_log_handler_list[0]= table_log_handler;
1350     slow_log_handler_list[1]= 0;
1351     break;
1352   case LOG_TABLE|LOG_FILE:
1353     slow_log_handler_list[0]= file_log_handler;
1354     slow_log_handler_list[1]= table_log_handler;
1355     slow_log_handler_list[2]= 0;
1356     break;
1357   }
1358 }
1359 
init_general_log(uint general_log_printer)1360 void LOGGER::init_general_log(uint general_log_printer)
1361 {
1362   if (general_log_printer & LOG_NONE)
1363   {
1364     general_log_handler_list[0]= 0;
1365     return;
1366   }
1367 
1368   switch (general_log_printer) {
1369   case LOG_FILE:
1370     general_log_handler_list[0]= file_log_handler;
1371     general_log_handler_list[1]= 0;
1372     break;
1373   case LOG_TABLE:
1374     general_log_handler_list[0]= table_log_handler;
1375     general_log_handler_list[1]= 0;
1376     break;
1377   case LOG_TABLE|LOG_FILE:
1378     general_log_handler_list[0]= file_log_handler;
1379     general_log_handler_list[1]= table_log_handler;
1380     general_log_handler_list[2]= 0;
1381     break;
1382   }
1383 }
1384 
1385 
activate_log_handler(THD * thd,uint log_type)1386 bool LOGGER::activate_log_handler(THD* thd, uint log_type)
1387 {
1388   MYSQL_QUERY_LOG *file_log;
1389   bool res= FALSE;
1390   lock_exclusive();
1391   switch (log_type) {
1392   case QUERY_LOG_SLOW:
1393     if (!opt_slow_log)
1394     {
1395       file_log= file_log_handler->get_mysql_slow_log();
1396 
1397       file_log->open_slow_log(opt_slow_logname);
1398       if (table_log_handler->activate_log(thd, QUERY_LOG_SLOW))
1399       {
1400         /* Error printed by open table in activate_log() */
1401         res= TRUE;
1402         file_log->close(0);
1403       }
1404       else
1405       {
1406         init_slow_log(log_output_options);
1407         opt_slow_log= TRUE;
1408       }
1409     }
1410     break;
1411   case QUERY_LOG_GENERAL:
1412     if (!opt_log)
1413     {
1414       file_log= file_log_handler->get_mysql_log();
1415 
1416       file_log->open_query_log(opt_logname);
1417       if (table_log_handler->activate_log(thd, QUERY_LOG_GENERAL))
1418       {
1419         /* Error printed by open table in activate_log() */
1420         res= TRUE;
1421         file_log->close(0);
1422       }
1423       else
1424       {
1425         init_general_log(log_output_options);
1426         opt_log= TRUE;
1427       }
1428     }
1429     break;
1430   default:
1431     DBUG_ASSERT(0);
1432   }
1433   unlock();
1434   return res;
1435 }
1436 
1437 
deactivate_log_handler(THD * thd,uint log_type)1438 void LOGGER::deactivate_log_handler(THD *thd, uint log_type)
1439 {
1440   my_bool *tmp_opt= 0;
1441   MYSQL_LOG *file_log;
1442 
1443   switch (log_type) {
1444   case QUERY_LOG_SLOW:
1445     tmp_opt= &opt_slow_log;
1446     file_log= file_log_handler->get_mysql_slow_log();
1447     break;
1448   case QUERY_LOG_GENERAL:
1449     tmp_opt= &opt_log;
1450     file_log= file_log_handler->get_mysql_log();
1451     break;
1452   default:
1453     MY_ASSERT_UNREACHABLE();
1454   }
1455 
1456   if (!(*tmp_opt))
1457     return;
1458 
1459   lock_exclusive();
1460   file_log->close(0);
1461   *tmp_opt= FALSE;
1462   unlock();
1463 }
1464 
1465 
1466 /* the parameters are unused for the log tables */
init()1467 bool Log_to_csv_event_handler::init()
1468 {
1469   return 0;
1470 }
1471 
set_handlers(uint error_log_printer,uint slow_log_printer,uint general_log_printer)1472 int LOGGER::set_handlers(uint error_log_printer,
1473                          uint slow_log_printer,
1474                          uint general_log_printer)
1475 {
1476   /* error log table is not supported yet */
1477   DBUG_ASSERT(error_log_printer < LOG_TABLE);
1478 
1479   lock_exclusive();
1480 
1481   if ((slow_log_printer & LOG_TABLE || general_log_printer & LOG_TABLE) &&
1482       !is_log_tables_initialized)
1483   {
1484     slow_log_printer= (slow_log_printer & ~LOG_TABLE) | LOG_FILE;
1485     general_log_printer= (general_log_printer & ~LOG_TABLE) | LOG_FILE;
1486 
1487     sql_print_error("Failed to initialize log tables. "
1488                     "Falling back to the old-fashioned logs");
1489   }
1490 
1491   init_error_log(error_log_printer);
1492   init_slow_log(slow_log_printer);
1493   init_general_log(general_log_printer);
1494 
1495   unlock();
1496 
1497   return 0;
1498 }
1499 
1500  /*
1501   Save position of binary log transaction cache.
1502 
1503   SYNPOSIS
1504     binlog_trans_log_savepos()
1505 
1506     thd      The thread to take the binlog data from
1507     pos      Pointer to variable where the position will be stored
1508 
1509   DESCRIPTION
1510 
1511     Save the current position in the binary log transaction cache into
1512     the variable pointed to by 'pos'
1513  */
1514 
1515 static void
binlog_trans_log_savepos(THD * thd,my_off_t * pos)1516 binlog_trans_log_savepos(THD *thd, my_off_t *pos)
1517 {
1518   DBUG_ENTER("binlog_trans_log_savepos");
1519   DBUG_ASSERT(pos != NULL);
1520   if (thd_get_ha_data(thd, binlog_hton) == NULL)
1521     thd->binlog_setup_trx_data();
1522   binlog_cache_mngr *const cache_mngr=
1523     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1524   DBUG_ASSERT(mysql_bin_log.is_open());
1525   *pos= cache_mngr->trx_cache.get_byte_position();
1526   DBUG_PRINT("return", ("*pos: %lu", (ulong) *pos));
1527   DBUG_VOID_RETURN;
1528 }
1529 
1530 
1531 /*
1532   Truncate the binary log transaction cache.
1533 
1534   SYNPOSIS
1535     binlog_trans_log_truncate()
1536 
1537     thd      The thread to take the binlog data from
1538     pos      Position to truncate to
1539 
1540   DESCRIPTION
1541 
1542     Truncate the binary log to the given position. Will not change
1543     anything else.
1544 
1545  */
1546 static void
binlog_trans_log_truncate(THD * thd,my_off_t pos)1547 binlog_trans_log_truncate(THD *thd, my_off_t pos)
1548 {
1549   DBUG_ENTER("binlog_trans_log_truncate");
1550   DBUG_PRINT("enter", ("pos: %lu", (ulong) pos));
1551 
1552   DBUG_ASSERT(thd_get_ha_data(thd, binlog_hton) != NULL);
1553   /* Only true if binlog_trans_log_savepos() wasn't called before */
1554   DBUG_ASSERT(pos != ~(my_off_t) 0);
1555 
1556   binlog_cache_mngr *const cache_mngr=
1557     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1558   cache_mngr->trx_cache.restore_savepoint(pos);
1559   DBUG_VOID_RETURN;
1560 }
1561 
1562 
1563 /*
1564   this function is mostly a placeholder.
1565   conceptually, binlog initialization (now mostly done in MYSQL_BIN_LOG::open)
1566   should be moved here.
1567 */
1568 
binlog_init(void * p)1569 int binlog_init(void *p)
1570 {
1571   binlog_hton= (handlerton *)p;
1572   binlog_hton->state=opt_bin_log ? SHOW_OPTION_YES : SHOW_OPTION_NO;
1573   binlog_hton->db_type=DB_TYPE_BINLOG;
1574   binlog_hton->savepoint_offset= sizeof(my_off_t);
1575   binlog_hton->close_connection= binlog_close_connection;
1576   binlog_hton->savepoint_set= binlog_savepoint_set;
1577   binlog_hton->savepoint_rollback= binlog_savepoint_rollback;
1578   binlog_hton->commit= binlog_commit;
1579   binlog_hton->rollback= binlog_rollback;
1580   binlog_hton->prepare= binlog_prepare;
1581   binlog_hton->flags= HTON_NOT_USER_SELECTABLE | HTON_HIDDEN;
1582   return 0;
1583 }
1584 
binlog_close_connection(handlerton * hton,THD * thd)1585 static int binlog_close_connection(handlerton *hton, THD *thd)
1586 {
1587   binlog_cache_mngr *const cache_mngr=
1588     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1589   DBUG_ASSERT(cache_mngr->trx_cache.empty() && cache_mngr->stmt_cache.empty());
1590   thd_set_ha_data(thd, binlog_hton, NULL);
1591   cache_mngr->~binlog_cache_mngr();
1592   my_free(cache_mngr);
1593   return 0;
1594 }
1595 
1596 /**
1597   This function flushes a cache upon commit/rollback.
1598 
1599   @param thd                The thread whose transaction should be flushed
1600   @param cache_data         Pointer to the cache
1601   @param end_ev             The end event either commit/rollback
1602   @param is_transactional   The type of the cache: transactional or
1603                             non-transactional
1604 
1605   @return
1606     nonzero if an error pops up when flushing the cache.
1607 */
1608 static inline int
binlog_flush_cache(THD * thd,binlog_cache_data * cache_data,Log_event * end_evt,bool is_transactional)1609 binlog_flush_cache(THD *thd, binlog_cache_data* cache_data, Log_event *end_evt,
1610                    bool is_transactional)
1611 {
1612   DBUG_ENTER("binlog_flush_cache");
1613   int error= 0;
1614 
1615   if (!cache_data->empty())
1616   {
1617     if (thd->binlog_flush_pending_rows_event(TRUE, is_transactional))
1618       DBUG_RETURN(1);
1619     /*
1620       Doing a commit or a rollback including non-transactional tables,
1621       i.e., ending a transaction where we might write the transaction
1622       cache to the binary log.
1623 
1624       We can always end the statement when ending a transaction since
1625       transactions are not allowed inside stored functions. If they
1626       were, we would have to ensure that we're not ending a statement
1627       inside a stored function.
1628     */
1629     error= mysql_bin_log.write(thd, &cache_data->cache_log, end_evt,
1630                                cache_data->has_incident());
1631   }
1632   cache_data->reset();
1633 
1634   DBUG_ASSERT(cache_data->empty());
1635   DBUG_RETURN(error);
1636 }
1637 
1638 /**
1639   This function flushes the stmt-cache upon commit.
1640 
1641   @param thd                The thread whose transaction should be flushed
1642   @param cache_mngr         Pointer to the cache manager
1643 
1644   @return
1645     nonzero if an error pops up when flushing the cache.
1646 */
1647 static inline int
binlog_commit_flush_stmt_cache(THD * thd,binlog_cache_mngr * cache_mngr)1648 binlog_commit_flush_stmt_cache(THD *thd,
1649                                binlog_cache_mngr *cache_mngr)
1650 {
1651   Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"),
1652                           FALSE, FALSE, TRUE, 0);
1653   return (binlog_flush_cache(thd, &cache_mngr->stmt_cache, &end_evt,
1654                              FALSE));
1655 }
1656 
1657 /**
1658   This function flushes the trx-cache upon commit.
1659 
1660   @param thd                The thread whose transaction should be flushed
1661   @param cache_mngr         Pointer to the cache manager
1662 
1663   @return
1664     nonzero if an error pops up when flushing the cache.
1665 */
1666 static inline int
binlog_commit_flush_trx_cache(THD * thd,binlog_cache_mngr * cache_mngr)1667 binlog_commit_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr)
1668 {
1669   Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"),
1670                           TRUE, FALSE, TRUE, 0);
1671   return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt,
1672                              TRUE));
1673 }
1674 
1675 /**
1676   This function flushes the trx-cache upon rollback.
1677 
1678   @param thd                The thread whose transaction should be flushed
1679   @param cache_mngr         Pointer to the cache manager
1680 
1681   @return
1682     nonzero if an error pops up when flushing the cache.
1683 */
1684 static inline int
binlog_rollback_flush_trx_cache(THD * thd,binlog_cache_mngr * cache_mngr)1685 binlog_rollback_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr)
1686 {
1687   Query_log_event end_evt(thd, STRING_WITH_LEN("ROLLBACK"),
1688                           TRUE, FALSE, TRUE, 0);
1689   return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt,
1690                              TRUE));
1691 }
1692 
1693 /**
1694   This function flushes the trx-cache upon commit.
1695 
1696   @param thd                The thread whose transaction should be flushed
1697   @param cache_mngr         Pointer to the cache manager
1698   @param xid                Transaction Id
1699 
1700   @return
1701     nonzero if an error pops up when flushing the cache.
1702 */
1703 static inline int
binlog_commit_flush_trx_cache(THD * thd,binlog_cache_mngr * cache_mngr,my_xid xid)1704 binlog_commit_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr,
1705                               my_xid xid)
1706 {
1707   Xid_log_event end_evt(thd, xid);
1708   return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt,
1709                              TRUE));
1710 }
1711 
1712 /**
1713   This function truncates the transactional cache upon committing or rolling
1714   back either a transaction or a statement.
1715 
1716   @param thd        The thread whose transaction should be flushed
1717   @param cache_mngr Pointer to the cache data to be flushed
1718   @param all        @c true means truncate the transaction, otherwise the
1719                     statement must be truncated.
1720 
1721   @return
1722     nonzero if an error pops up when truncating the transactional cache.
1723 */
1724 static int
binlog_truncate_trx_cache(THD * thd,binlog_cache_mngr * cache_mngr,bool all)1725 binlog_truncate_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr, bool all)
1726 {
1727   DBUG_ENTER("binlog_truncate_trx_cache");
1728   int error=0;
1729   /*
1730     This function handles transactional changes and as such this flag
1731     equals to true.
1732   */
1733   bool const is_transactional= TRUE;
1734 
1735   DBUG_PRINT("info", ("thd->options={ %s %s}, transaction: %s",
1736                       FLAGSTR(thd->variables.option_bits, OPTION_NOT_AUTOCOMMIT),
1737                       FLAGSTR(thd->variables.option_bits, OPTION_BEGIN),
1738                       all ? "all" : "stmt"));
1739 
1740   thd->binlog_remove_pending_rows_event(TRUE, is_transactional);
1741   /*
1742     If rolling back an entire transaction or a single statement not
1743     inside a transaction, we reset the transaction cache.
1744   */
1745   if (ending_trans(thd, all))
1746   {
1747     if (cache_mngr->trx_cache.has_incident())
1748       error= mysql_bin_log.write_incident(thd, TRUE);
1749 
1750     thd->clear_binlog_table_maps();
1751 
1752     cache_mngr->reset_cache(&cache_mngr->trx_cache);
1753   }
1754   /*
1755     If rolling back a statement in a transaction, we truncate the
1756     transaction cache to remove the statement.
1757   */
1758   else
1759     cache_mngr->trx_cache.restore_prev_position();
1760 
1761   DBUG_ASSERT(thd->binlog_get_pending_rows_event(is_transactional) == NULL);
1762   DBUG_RETURN(error);
1763 }
1764 
binlog_prepare(handlerton * hton,THD * thd,bool all)1765 static int binlog_prepare(handlerton *hton, THD *thd, bool all)
1766 {
1767   /*
1768     do nothing.
1769     just pretend we can do 2pc, so that MySQL won't
1770     switch to 1pc.
1771     real work will be done in MYSQL_BIN_LOG::log_xid()
1772   */
1773   return 0;
1774 }
1775 
1776 /**
1777   This function is called once after each statement.
1778 
1779   It has the responsibility to flush the caches to the binary log on commits.
1780 
1781   @param hton  The binlog handlerton.
1782   @param thd   The client thread that executes the transaction.
1783   @param all   This is @c true if this is a real transaction commit, and
1784                @false otherwise.
1785 
1786   @see handlerton::commit
1787 */
binlog_commit(handlerton * hton,THD * thd,bool all)1788 static int binlog_commit(handlerton *hton, THD *thd, bool all)
1789 {
1790   int error= 0;
1791   DBUG_ENTER("binlog_commit");
1792   binlog_cache_mngr *const cache_mngr=
1793     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1794 
1795   DBUG_PRINT("debug",
1796              ("all: %d, in_transaction: %s, all.modified_non_trans_table: %s, stmt.modified_non_trans_table: %s",
1797               all,
1798               YESNO(thd->in_multi_stmt_transaction_mode()),
1799               YESNO(thd->transaction.all.modified_non_trans_table),
1800               YESNO(thd->transaction.stmt.modified_non_trans_table)));
1801 
1802   if (!cache_mngr->stmt_cache.empty())
1803   {
1804     error= binlog_commit_flush_stmt_cache(thd, cache_mngr);
1805   }
1806 
1807   if (cache_mngr->trx_cache.empty())
1808   {
1809     /*
1810       we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid()
1811     */
1812     cache_mngr->reset_cache(&cache_mngr->trx_cache);
1813     DBUG_RETURN(error);
1814   }
1815 
1816   /*
1817     We commit the transaction if:
1818      - We are not in a transaction and committing a statement, or
1819      - We are in a transaction and a full transaction is committed.
1820     Otherwise, we accumulate the changes.
1821   */
1822   if (!error && ending_trans(thd, all))
1823     error= binlog_commit_flush_trx_cache(thd, cache_mngr);
1824 
1825   /*
1826     This is part of the stmt rollback.
1827   */
1828   if (!all)
1829     cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF);
1830 
1831   DBUG_RETURN(error);
1832 }
1833 
1834 /**
1835   This function is called when a transaction or a statement is rolled back.
1836 
1837   @param hton  The binlog handlerton.
1838   @param thd   The client thread that executes the transaction.
1839   @param all   This is @c true if this is a real transaction rollback, and
1840                @false otherwise.
1841 
1842   @see handlerton::rollback
1843 */
binlog_rollback(handlerton * hton,THD * thd,bool all)1844 static int binlog_rollback(handlerton *hton, THD *thd, bool all)
1845 {
1846   DBUG_ENTER("binlog_rollback");
1847   int error= 0;
1848   binlog_cache_mngr *const cache_mngr=
1849     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1850 
1851   DBUG_PRINT("debug", ("all: %s, all.modified_non_trans_table: %s, stmt.modified_non_trans_table: %s",
1852                        YESNO(all),
1853                        YESNO(thd->transaction.all.modified_non_trans_table),
1854                        YESNO(thd->transaction.stmt.modified_non_trans_table)));
1855 
1856   /*
1857     If an incident event is set we do not flush the content of the statement
1858     cache because it may be corrupted.
1859   */
1860   if (cache_mngr->stmt_cache.has_incident())
1861   {
1862     error= mysql_bin_log.write_incident(thd, TRUE);
1863     cache_mngr->reset_cache(&cache_mngr->stmt_cache);
1864   }
1865   else if (!cache_mngr->stmt_cache.empty())
1866   {
1867     error= binlog_commit_flush_stmt_cache(thd, cache_mngr);
1868   }
1869 
1870   if (cache_mngr->trx_cache.empty())
1871   {
1872     /*
1873       we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid()
1874     */
1875     cache_mngr->reset_cache(&cache_mngr->trx_cache);
1876     DBUG_RETURN(error);
1877   }
1878 
1879   if (mysql_bin_log.check_write_error(thd))
1880   {
1881     /*
1882       "all == true" means that a "rollback statement" triggered the error and
1883       this function was called. However, this must not happen as a rollback
1884       is written directly to the binary log. And in auto-commit mode, a single
1885       statement that is rolled back has the flag all == false.
1886     */
1887     DBUG_ASSERT(!all);
1888     /*
1889       We reach this point if the effect of a statement did not properly get into
1890       a cache and need to be rolled back.
1891     */
1892     error |= binlog_truncate_trx_cache(thd, cache_mngr, all);
1893   }
1894   else if (!error)
1895   {
1896     /*
1897       We flush the cache wrapped in a beging/rollback if:
1898         . aborting a single or multi-statement transaction and;
1899         . the OPTION_KEEP_LOG is active or;
1900         . the format is STMT and a non-trans table was updated or;
1901         . the format is MIXED and a temporary non-trans table was
1902           updated or;
1903         . the format is MIXED, non-trans table was updated and
1904           aborting a single statement transaction;
1905     */
1906     if (ending_trans(thd, all) &&
1907         ((thd->variables.option_bits & OPTION_KEEP_LOG) ||
1908          (trans_has_updated_non_trans_table(thd) &&
1909           thd->variables.binlog_format == BINLOG_FORMAT_STMT) ||
1910          (cache_mngr->trx_cache.changes_to_non_trans_temp_table() &&
1911           thd->variables.binlog_format == BINLOG_FORMAT_MIXED) ||
1912          (trans_has_updated_non_trans_table(thd) &&
1913           ending_single_stmt_trans(thd,all) &&
1914           thd->variables.binlog_format == BINLOG_FORMAT_MIXED)))
1915       error= binlog_rollback_flush_trx_cache(thd, cache_mngr);
1916     /*
1917       Truncate the cache if:
1918         . aborting a single or multi-statement transaction or;
1919         . the OPTION_KEEP_LOG is not active and;
1920         . the format is not STMT or no non-trans table was
1921           updated and;
1922         . the format is not MIXED or no temporary non-trans table
1923           was updated.
1924     */
1925     else if (ending_trans(thd, all) ||
1926              (!(thd->variables.option_bits & OPTION_KEEP_LOG) &&
1927               (!stmt_has_updated_non_trans_table(thd) ||
1928                thd->variables.binlog_format != BINLOG_FORMAT_STMT) &&
1929               (!cache_mngr->trx_cache.changes_to_non_trans_temp_table() ||
1930                thd->variables.binlog_format != BINLOG_FORMAT_MIXED)))
1931       error= binlog_truncate_trx_cache(thd, cache_mngr, all);
1932   }
1933 
1934   /*
1935     This is part of the stmt rollback.
1936   */
1937   if (!all)
1938     cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF);
1939 
1940   DBUG_RETURN(error);
1941 }
1942 
set_write_error(THD * thd,bool is_transactional)1943 void MYSQL_BIN_LOG::set_write_error(THD *thd, bool is_transactional)
1944 {
1945   DBUG_ENTER("MYSQL_BIN_LOG::set_write_error");
1946 
1947   write_error= 1;
1948 
1949   if (check_write_error(thd))
1950     DBUG_VOID_RETURN;
1951 
1952   if (my_errno == EFBIG)
1953   {
1954     if (is_transactional)
1955     {
1956       my_message(ER_TRANS_CACHE_FULL, ER(ER_TRANS_CACHE_FULL), MYF(MY_WME));
1957     }
1958     else
1959     {
1960       my_message(ER_STMT_CACHE_FULL, ER(ER_STMT_CACHE_FULL), MYF(MY_WME));
1961     }
1962   }
1963   else
1964   {
1965     my_error(ER_ERROR_ON_WRITE, MYF(MY_WME), name, errno);
1966   }
1967 
1968   DBUG_VOID_RETURN;
1969 }
1970 
check_write_error(THD * thd)1971 bool MYSQL_BIN_LOG::check_write_error(THD *thd)
1972 {
1973   DBUG_ENTER("MYSQL_BIN_LOG::check_write_error");
1974 
1975   bool checked= FALSE;
1976 
1977   if (!thd->is_error())
1978     DBUG_RETURN(checked);
1979 
1980   switch (thd->stmt_da->sql_errno())
1981   {
1982     case ER_TRANS_CACHE_FULL:
1983     case ER_STMT_CACHE_FULL:
1984     case ER_ERROR_ON_WRITE:
1985     case ER_BINLOG_LOGGING_IMPOSSIBLE:
1986       checked= TRUE;
1987     break;
1988   }
1989 
1990   DBUG_RETURN(checked);
1991 }
1992 
1993 /**
1994   @note
1995   How do we handle this (unlikely but legal) case:
1996   @verbatim
1997     [transaction] + [update to non-trans table] + [rollback to savepoint] ?
1998   @endverbatim
1999   The problem occurs when a savepoint is before the update to the
2000   non-transactional table. Then when there's a rollback to the savepoint, if we
2001   simply truncate the binlog cache, we lose the part of the binlog cache where
2002   the update is. If we want to not lose it, we need to write the SAVEPOINT
2003   command and the ROLLBACK TO SAVEPOINT command to the binlog cache. The latter
2004   is easy: it's just write at the end of the binlog cache, but the former
2005   should be *inserted* to the place where the user called SAVEPOINT. The
2006   solution is that when the user calls SAVEPOINT, we write it to the binlog
2007   cache (so no need to later insert it). As transactions are never intermixed
2008   in the binary log (i.e. they are serialized), we won't have conflicts with
2009   savepoint names when using mysqlbinlog or in the slave SQL thread.
2010   Then when ROLLBACK TO SAVEPOINT is called, if we updated some
2011   non-transactional table, we don't truncate the binlog cache but instead write
2012   ROLLBACK TO SAVEPOINT to it; otherwise we truncate the binlog cache (which
2013   will chop the SAVEPOINT command from the binlog cache, which is good as in
2014   that case there is no need to have it in the binlog).
2015 */
2016 
binlog_savepoint_set(handlerton * hton,THD * thd,void * sv)2017 static int binlog_savepoint_set(handlerton *hton, THD *thd, void *sv)
2018 {
2019   DBUG_ENTER("binlog_savepoint_set");
2020 
2021   binlog_trans_log_savepos(thd, (my_off_t*) sv);
2022 
2023   // buffer to store quoted identifier
2024   char* buffer= (char *)my_malloc(sizeof("SAVEPOINT ")+ 1 + NAME_LEN * 2 + 2,
2025                                   MYF(0));
2026   String log_query(buffer, sizeof(buffer), system_charset_info);
2027   log_query.length(0);
2028 
2029   /* Write it to the binary log */
2030 
2031   if (log_query.append(STRING_WITH_LEN("SAVEPOINT ")))
2032     DBUG_RETURN(1);
2033   else
2034     append_identifier(thd, &log_query, thd->lex->ident.str,
2035                       thd->lex->ident.length);
2036   int errcode= query_error_code(thd, thd->killed == THD::NOT_KILLED);
2037   Query_log_event qinfo(thd, log_query.c_ptr_safe(), log_query.length(),
2038                         TRUE, FALSE, TRUE, errcode);
2039   my_free(buffer);
2040   DBUG_RETURN(mysql_bin_log.write(&qinfo));
2041 }
2042 
binlog_savepoint_rollback(handlerton * hton,THD * thd,void * sv)2043 static int binlog_savepoint_rollback(handlerton *hton, THD *thd, void *sv)
2044 {
2045   DBUG_ENTER("binlog_savepoint_rollback");
2046 
2047   /*
2048     Write ROLLBACK TO SAVEPOINT to the binlog cache if we have updated some
2049     non-transactional table. Otherwise, truncate the binlog cache starting
2050     from the SAVEPOINT command.
2051   */
2052   if (unlikely(trans_has_updated_non_trans_table(thd) ||
2053                (thd->variables.option_bits & OPTION_KEEP_LOG)))
2054   {
2055     // buffer to store rollback query with quoted identifier
2056     char* buffer= (char *)my_malloc(12 + 1 + NAME_LEN * 2 + 2, MYF(0));
2057     String log_query(buffer, sizeof(buffer), system_charset_info);
2058     log_query.length(0);
2059 
2060     if (log_query.append(STRING_WITH_LEN("ROLLBACK TO ")))
2061       DBUG_RETURN(1);
2062     else
2063       append_identifier(thd, &log_query, thd->lex->ident.str,
2064                         thd->lex->ident.length);
2065     int errcode= query_error_code(thd, thd->killed == THD::NOT_KILLED);
2066     Query_log_event qinfo(thd, log_query.c_ptr_safe(), log_query.length(),
2067                           TRUE, FALSE, TRUE, errcode);
2068     my_free(buffer);
2069     DBUG_RETURN(mysql_bin_log.write(&qinfo));
2070   }
2071   binlog_trans_log_truncate(thd, *(my_off_t*)sv);
2072   DBUG_RETURN(0);
2073 }
2074 
2075 
check_binlog_magic(IO_CACHE * log,const char ** errmsg)2076 int check_binlog_magic(IO_CACHE* log, const char** errmsg)
2077 {
2078   char magic[4];
2079   DBUG_ASSERT(my_b_tell(log) == 0);
2080 
2081   if (my_b_read(log, (uchar*) magic, sizeof(magic)))
2082   {
2083     *errmsg = "I/O error reading the header from the binary log";
2084     sql_print_error("%s, errno=%d, io cache code=%d", *errmsg, my_errno,
2085 		    log->error);
2086     return 1;
2087   }
2088   if (memcmp(magic, BINLOG_MAGIC, sizeof(magic)))
2089   {
2090     *errmsg = "Binlog has bad magic number;  It's not a binary log file that can be used by this version of MySQL";
2091     return 1;
2092   }
2093   return 0;
2094 }
2095 
2096 
open_binlog(IO_CACHE * log,const char * log_file_name,const char ** errmsg)2097 File open_binlog(IO_CACHE *log, const char *log_file_name, const char **errmsg)
2098 {
2099   File file;
2100   DBUG_ENTER("open_binlog");
2101 
2102   if ((file= mysql_file_open(key_file_binlog,
2103                              log_file_name, O_RDONLY | O_BINARY | O_SHARE,
2104                              MYF(MY_WME))) < 0)
2105   {
2106     sql_print_error("Failed to open log (file '%s', errno %d)",
2107                     log_file_name, my_errno);
2108     *errmsg = "Could not open log file";
2109     goto err;
2110   }
2111   if (init_io_cache(log, file, IO_SIZE*2, READ_CACHE, 0, 0,
2112                     MYF(MY_WME|MY_DONT_CHECK_FILESIZE)))
2113   {
2114     sql_print_error("Failed to create a cache on log (file '%s')",
2115                     log_file_name);
2116     *errmsg = "Could not open log file";
2117     goto err;
2118   }
2119   if (check_binlog_magic(log,errmsg))
2120     goto err;
2121   DBUG_RETURN(file);
2122 
2123 err:
2124   if (file >= 0)
2125   {
2126     mysql_file_close(file, MYF(0));
2127     end_io_cache(log);
2128   }
2129   DBUG_RETURN(-1);
2130 }
2131 
2132 #ifdef _WIN32
2133 static int eventSource = 0;
2134 
setup_windows_event_source()2135 static void setup_windows_event_source()
2136 {
2137   HKEY    hRegKey= NULL;
2138   DWORD   dwError= 0;
2139   TCHAR   szPath[MAX_PATH];
2140   DWORD dwTypes;
2141 
2142   if (eventSource)               // Ensure that we are only called once
2143     return;
2144   eventSource= 1;
2145 
2146   // Create the event source registry key
2147   dwError= RegCreateKey(HKEY_LOCAL_MACHINE,
2148                           "SYSTEM\\CurrentControlSet\\Services\\EventLog\\Application\\MySQL",
2149                           &hRegKey);
2150 
2151   /* Name of the PE module that contains the message resource */
2152   GetModuleFileName(NULL, szPath, MAX_PATH);
2153 
2154   /* Register EventMessageFile */
2155   dwError = RegSetValueEx(hRegKey, "EventMessageFile", 0, REG_EXPAND_SZ,
2156                           (PBYTE) szPath, (DWORD) (strlen(szPath) + 1));
2157 
2158   /* Register supported event types */
2159   dwTypes= (EVENTLOG_ERROR_TYPE | EVENTLOG_WARNING_TYPE |
2160             EVENTLOG_INFORMATION_TYPE);
2161   dwError= RegSetValueEx(hRegKey, "TypesSupported", 0, REG_DWORD,
2162                          (LPBYTE) &dwTypes, sizeof dwTypes);
2163 
2164   RegCloseKey(hRegKey);
2165 }
2166 
2167 #endif /* _WIN32 */
2168 
2169 
2170 /**
2171   Find a unique filename for 'filename.#'.
2172 
2173   Set '#' to the number next to the maximum found in the most
2174   recent log file extension.
2175 
2176   This function will return nonzero if: (i) the generated name
2177   exceeds FN_REFLEN; (ii) if the number of extensions is exhausted;
2178   or (iii) some other error happened while examining the filesystem.
2179 
2180   @return
2181     nonzero if not possible to get unique filename.
2182 */
2183 
find_uniq_filename(char * name)2184 static int find_uniq_filename(char *name)
2185 {
2186   uint                  i;
2187   char                  buff[FN_REFLEN], ext_buf[FN_REFLEN];
2188   struct st_my_dir     *dir_info;
2189   reg1 struct fileinfo *file_info;
2190   ulong                 max_found= 0, next= 0, number= 0;
2191   size_t		buf_length, length;
2192   char			*start, *end;
2193   int                   error= 0;
2194   DBUG_ENTER("find_uniq_filename");
2195 
2196   length= dirname_part(buff, name, &buf_length);
2197   start=  name + length;
2198   end=    strend(start);
2199 
2200   *end='.';
2201   length= (size_t) (end - start + 1);
2202 
2203   if ((DBUG_EVALUATE_IF("error_unique_log_filename", 1,
2204       !(dir_info= my_dir(buff,MYF(MY_DONT_SORT))))))
2205   {						// This shouldn't happen
2206     strmov(end,".1");				// use name+1
2207     DBUG_RETURN(1);
2208   }
2209   file_info= dir_info->dir_entry;
2210   for (i= dir_info->number_off_files ; i-- ; file_info++)
2211   {
2212     if (strncmp(file_info->name, start, length) == 0 &&
2213 	test_if_number(file_info->name+length, &number,0))
2214     {
2215       set_if_bigger(max_found,(ulong) number);
2216     }
2217   }
2218   my_dirend(dir_info);
2219 
2220   /* check if reached the maximum possible extension number */
2221   if ((max_found == MAX_LOG_UNIQUE_FN_EXT))
2222   {
2223     sql_print_error("Log filename extension number exhausted: %06lu. \
2224 Please fix this by archiving old logs and \
2225 updating the index files.", max_found);
2226     error= 1;
2227     goto end;
2228   }
2229 
2230   next= max_found + 1;
2231   if (sprintf(ext_buf, "%06lu", next)<0)
2232   {
2233     error= 1;
2234     goto end;
2235   }
2236   *end++='.';
2237 
2238   /*
2239     Check if the generated extension size + the file name exceeds the
2240     buffer size used. If one did not check this, then the filename might be
2241     truncated, resulting in error.
2242    */
2243   if (((strlen(ext_buf) + (end - name)) >= FN_REFLEN))
2244   {
2245     sql_print_error("Log filename too large: %s%s (%zu). \
2246 Please fix this by archiving old logs and updating the \
2247 index files.", name, ext_buf, (strlen(ext_buf) + (end - name)));
2248     error= 1;
2249     goto end;
2250   }
2251 
2252   if (sprintf(end, "%06lu", next)<0)
2253   {
2254     error= 1;
2255     goto end;
2256   }
2257 
2258   /* print warning if reaching the end of available extensions. */
2259   if ((next > (MAX_LOG_UNIQUE_FN_EXT - LOG_WARN_UNIQUE_FN_EXT_LEFT)))
2260     sql_print_warning("Next log extension: %lu. \
2261 Remaining log filename extensions: %lu. \
2262 Please consider archiving some logs.", next, (MAX_LOG_UNIQUE_FN_EXT - next));
2263 
2264 end:
2265   DBUG_RETURN(error);
2266 }
2267 
2268 
init(enum_log_type log_type_arg,enum cache_type io_cache_type_arg)2269 void MYSQL_LOG::init(enum_log_type log_type_arg,
2270                      enum cache_type io_cache_type_arg)
2271 {
2272   DBUG_ENTER("MYSQL_LOG::init");
2273   log_type= log_type_arg;
2274   io_cache_type= io_cache_type_arg;
2275   DBUG_PRINT("info",("log_type: %d", log_type));
2276   DBUG_VOID_RETURN;
2277 }
2278 
2279 
init_and_set_log_file_name(const char * log_name,const char * new_name,enum_log_type log_type_arg,enum cache_type io_cache_type_arg)2280 bool MYSQL_LOG::init_and_set_log_file_name(const char *log_name,
2281                                            const char *new_name,
2282                                            enum_log_type log_type_arg,
2283                                            enum cache_type io_cache_type_arg)
2284 {
2285   init(log_type_arg, io_cache_type_arg);
2286 
2287   if (new_name && !strmov(log_file_name, new_name))
2288     return TRUE;
2289   else if (!new_name && generate_new_name(log_file_name, log_name))
2290     return TRUE;
2291 
2292   return FALSE;
2293 }
2294 
2295 
is_valid_log_name(const char * name,size_t len)2296 bool is_valid_log_name(const char *name, size_t len)
2297 {
2298   if (len > 3)
2299   {
2300     const char *tail= name + len - 4;
2301     if (my_strcasecmp(system_charset_info, tail, ".ini") == 0 ||
2302         my_strcasecmp(system_charset_info, tail, ".cnf") == 0)
2303     {
2304       return false;
2305     }
2306   }
2307   return true;
2308 }
2309 
2310 
2311 /**
2312   Get the real log file name, and possibly reopen file.
2313 
2314   Use realpath() to get the path with symbolic links
2315   expanded. Then, close the file, and reopen the real path using the
2316   O_NOFOLLOW flag. This will reject following symbolic links.
2317 
2318   @param          file                  File descriptor.
2319   @param          log_file_key          Key for P_S instrumentation.
2320   @param          open_flags            Flags to use for opening the file.
2321   @param          opened_file_name      Name of the open fd.
2322 
2323   @retval file descriptor to open file with 'real_file_name', or '-1'
2324           in case of errors.
2325 */
2326 
2327 #ifndef _WIN32
mysql_file_real_name_reopen(File file,PSI_file_key log_file_key,int open_flags,const char * opened_file_name)2328 static File mysql_file_real_name_reopen(File file,
2329 #ifdef HAVE_PSI_INTERFACE
2330                                         PSI_file_key log_file_key,
2331 #endif
2332                                         int open_flags,
2333                                         const char *opened_file_name)
2334 {
2335   DBUG_ASSERT(file);
2336   DBUG_ASSERT(opened_file_name);
2337 
2338   /* Buffer for realpath must have capacity for PATH_MAX. */
2339   char real_file_name[PATH_MAX];
2340 
2341   /* Get realpath, validate, open realpath with O_NOFOLLOW. */
2342   if (realpath(opened_file_name, real_file_name) == NULL)
2343   {
2344     (void) mysql_file_close(file, MYF(0));
2345     return -1;
2346   }
2347 
2348   if (mysql_file_close(file, MYF(0)))
2349     return -1;
2350 
2351   if (strlen(real_file_name) > FN_REFLEN)
2352     return -1;
2353 
2354   if (!is_valid_log_name(real_file_name, strlen(real_file_name)))
2355   {
2356     sql_print_error("Invalid log file name after expanding symlinks: '%s'",
2357                     real_file_name);
2358     return -1;
2359   }
2360 
2361   return mysql_file_open(log_file_key, real_file_name,
2362                          open_flags | O_NOFOLLOW,
2363                          MYF(MY_WME | ME_WAITTANG));
2364 }
2365 #endif // _WIN32
2366 
2367 /*
2368   Open a (new) log file.
2369 
2370   SYNOPSIS
2371     open()
2372 
2373     log_name            The name of the log to open
2374     log_type_arg        The type of the log. E.g. LOG_NORMAL
2375     new_name            The new name for the logfile. This is only needed
2376                         when the method is used to open the binlog file.
2377     io_cache_type_arg   The type of the IO_CACHE to use for this log file
2378 
2379   DESCRIPTION
2380     Open the logfile, init IO_CACHE and write startup messages
2381     (in case of general and slow query logs).
2382 
2383   RETURN VALUES
2384     0   ok
2385     1   error
2386 */
2387 
open(PSI_file_key log_file_key,const char * log_name,enum_log_type log_type_arg,const char * new_name,enum cache_type io_cache_type_arg)2388 bool MYSQL_LOG::open(
2389 #ifdef HAVE_PSI_INTERFACE
2390                      PSI_file_key log_file_key,
2391 #endif
2392                      const char *log_name, enum_log_type log_type_arg,
2393                      const char *new_name, enum cache_type io_cache_type_arg)
2394 {
2395   char buff[FN_REFLEN];
2396   MY_STAT f_stat;
2397   File file= -1;
2398   int open_flags= O_CREAT | O_BINARY;
2399   DBUG_ENTER("MYSQL_LOG::open");
2400   DBUG_PRINT("enter", ("log_type: %d", (int) log_type_arg));
2401 
2402   write_error= 0;
2403 
2404   if (!(name= my_strdup(log_name, MYF(MY_WME))))
2405   {
2406     name= (char *)log_name; // for the error message
2407     goto err;
2408   }
2409 
2410   if (init_and_set_log_file_name(name, new_name,
2411                                  log_type_arg, io_cache_type_arg))
2412     goto err;
2413 
2414   /* File is regular writable file */
2415   if (my_stat(log_file_name, &f_stat, MYF(0)) && !MY_S_ISREG(f_stat.st_mode))
2416     goto err;
2417 
2418   if (io_cache_type == SEQ_READ_APPEND)
2419     open_flags |= O_RDWR | O_APPEND;
2420   else
2421     open_flags |= O_WRONLY | (log_type == LOG_BIN ? 0 : O_APPEND);
2422 
2423   db[0]= 0;
2424 
2425 #ifdef HAVE_PSI_INTERFACE
2426   /* Keep the key for reopen */
2427   m_log_file_key= log_file_key;
2428 #endif
2429 
2430   if ((file= mysql_file_open(log_file_key,
2431                              log_file_name, open_flags,
2432                              MYF(MY_WME | ME_WAITTANG))) < 0)
2433     goto err;
2434 
2435 #ifndef _WIN32
2436   /* Reopen and validate path. */
2437   if ((log_type_arg == LOG_UNKNOWN || log_type_arg == LOG_NORMAL) &&
2438       (file= mysql_file_real_name_reopen(file,
2439 #ifdef HAVE_PSI_INTERFACE
2440                                          log_file_key,
2441 #endif
2442                                          open_flags,
2443                                          log_file_name)) < 0)
2444     goto err;
2445 #endif // _WIN32
2446 
2447   if (init_io_cache(&log_file, file, IO_SIZE, io_cache_type,
2448                     mysql_file_tell(file, MYF(MY_WME)), 0,
2449                     MYF(MY_WME | MY_NABP |
2450                         ((log_type == LOG_BIN) ? MY_WAIT_IF_FULL : 0))))
2451     goto err;
2452 
2453   if (log_type == LOG_NORMAL)
2454   {
2455     char *end;
2456     int len=my_snprintf(buff, sizeof(buff), "%s, Version: %s (%s). "
2457 #ifdef EMBEDDED_LIBRARY
2458                         "embedded library\n",
2459                         my_progname, server_version, MYSQL_COMPILATION_COMMENT
2460 #elif _WIN32
2461 			"started with:\nTCP Port: %d, Named Pipe: %s\n",
2462                         my_progname, server_version, MYSQL_COMPILATION_COMMENT,
2463                         mysqld_port, mysqld_unix_port
2464 #else
2465 			"started with:\nTcp port: %d  Unix socket: %s\n",
2466                         my_progname, server_version, MYSQL_COMPILATION_COMMENT,
2467                         mysqld_port, mysqld_unix_port
2468 #endif
2469                        );
2470     end= strnmov(buff + len, "Time                 Id Command    Argument\n",
2471                  sizeof(buff) - len);
2472     if (my_b_write(&log_file, (uchar*) buff, (uint) (end-buff)) ||
2473 	flush_io_cache(&log_file))
2474       goto err;
2475   }
2476 
2477   log_state= LOG_OPENED;
2478   DBUG_RETURN(0);
2479 
2480 err:
2481   sql_print_error("Could not use %s for logging (error %d). \
2482 Turning logging off for the whole duration of the MySQL server process. \
2483 To turn it on again: fix the cause, \
2484 shutdown the MySQL server and restart it.", name, errno);
2485   if (file >= 0)
2486     mysql_file_close(file, MYF(0));
2487   end_io_cache(&log_file);
2488   my_free(name);
2489   name= NULL;
2490   log_state= LOG_CLOSED;
2491   DBUG_RETURN(1);
2492 }
2493 
MYSQL_LOG()2494 MYSQL_LOG::MYSQL_LOG()
2495   : name(0), write_error(FALSE), inited(FALSE), log_type(LOG_UNKNOWN),
2496     log_state(LOG_CLOSED)
2497 {
2498   /*
2499     We don't want to initialize LOCK_Log here as such initialization depends on
2500     safe_mutex (when using safe_mutex) which depends on MY_INIT(), which is
2501     called only in main(). Doing initialization here would make it happen
2502     before main().
2503   */
2504   bzero((char*) &log_file, sizeof(log_file));
2505 }
2506 
init_pthread_objects()2507 void MYSQL_LOG::init_pthread_objects()
2508 {
2509   DBUG_ASSERT(inited == 0);
2510   inited= 1;
2511   mysql_mutex_init(key_LOG_LOCK_log, &LOCK_log, MY_MUTEX_INIT_SLOW);
2512 }
2513 
2514 /*
2515   Close the log file
2516 
2517   SYNOPSIS
2518     close()
2519     exiting     Bitmask. For the slow and general logs the only used bit is
2520                 LOG_CLOSE_TO_BE_OPENED. This is used if we intend to call
2521                 open at once after close.
2522 
2523   NOTES
2524     One can do an open on the object at once after doing a close.
2525     The internal structures are not freed until cleanup() is called
2526 */
2527 
close(uint exiting)2528 void MYSQL_LOG::close(uint exiting)
2529 {					// One can't set log_type here!
2530   DBUG_ENTER("MYSQL_LOG::close");
2531   DBUG_PRINT("enter",("exiting: %d", (int) exiting));
2532   if (log_state == LOG_OPENED)
2533   {
2534     end_io_cache(&log_file);
2535 
2536     if (mysql_file_sync(log_file.file, MYF(MY_WME)) && ! write_error)
2537     {
2538       write_error= 1;
2539       sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
2540     }
2541 
2542     if (mysql_file_close(log_file.file, MYF(MY_WME)) && ! write_error)
2543     {
2544       write_error= 1;
2545       sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
2546     }
2547   }
2548 
2549   log_state= (exiting & LOG_CLOSE_TO_BE_OPENED) ? LOG_TO_BE_OPENED : LOG_CLOSED;
2550   my_free(name);
2551   name= NULL;
2552   DBUG_VOID_RETURN;
2553 }
2554 
2555 /** This is called only once. */
2556 
cleanup()2557 void MYSQL_LOG::cleanup()
2558 {
2559   DBUG_ENTER("cleanup");
2560   if (inited)
2561   {
2562     inited= 0;
2563     mysql_mutex_destroy(&LOCK_log);
2564     close(0);
2565   }
2566   DBUG_VOID_RETURN;
2567 }
2568 
2569 
generate_new_name(char * new_name,const char * log_name)2570 int MYSQL_LOG::generate_new_name(char *new_name, const char *log_name)
2571 {
2572   fn_format(new_name, log_name, mysql_data_home, "", 4);
2573   if (log_type == LOG_BIN)
2574   {
2575     if (!fn_ext(log_name)[0])
2576     {
2577       if (find_uniq_filename(new_name))
2578       {
2579         my_printf_error(ER_NO_UNIQUE_LOGFILE, ER(ER_NO_UNIQUE_LOGFILE),
2580                         MYF(ME_FATALERROR), log_name);
2581 	sql_print_error(ER(ER_NO_UNIQUE_LOGFILE), log_name);
2582 	return 1;
2583       }
2584     }
2585   }
2586   return 0;
2587 }
2588 
2589 
2590 /*
2591   Reopen the log file
2592 
2593   SYNOPSIS
2594     reopen_file()
2595 
2596   DESCRIPTION
2597     Reopen the log file. The method is used during FLUSH LOGS
2598     and locks LOCK_log mutex
2599 */
2600 
2601 
reopen_file()2602 void MYSQL_QUERY_LOG::reopen_file()
2603 {
2604   char *save_name;
2605 
2606   DBUG_ENTER("MYSQL_LOG::reopen_file");
2607   if (!is_open())
2608   {
2609     DBUG_PRINT("info",("log is closed"));
2610     DBUG_VOID_RETURN;
2611   }
2612 
2613   mysql_mutex_lock(&LOCK_log);
2614 
2615   save_name= name;
2616   name= 0;				// Don't free name
2617   close(LOG_CLOSE_TO_BE_OPENED);
2618 
2619   /*
2620      Note that at this point, log_state != LOG_CLOSED (important for is_open()).
2621   */
2622 
2623   open(
2624 #ifdef HAVE_PSI_INTERFACE
2625        m_log_file_key,
2626 #endif
2627        save_name, log_type, 0, io_cache_type);
2628   my_free(save_name);
2629 
2630   mysql_mutex_unlock(&LOCK_log);
2631 
2632   DBUG_VOID_RETURN;
2633 }
2634 
2635 
2636 /*
2637   Write a command to traditional general log file
2638 
2639   SYNOPSIS
2640     write()
2641 
2642     event_time        command start timestamp
2643     user_host         the pointer to the string with user@host info
2644     user_host_len     length of the user_host string. this is computed once
2645                       and passed to all general log  event handlers
2646     thread_id         Id of the thread, issued a query
2647     command_type      the type of the command being logged
2648     command_type_len  the length of the string above
2649     sql_text          the very text of the query being executed
2650     sql_text_len      the length of sql_text string
2651 
2652   DESCRIPTION
2653 
2654    Log given command to to normal (not rotable) log file
2655 
2656   RETURN
2657     FASE - OK
2658     TRUE - error occured
2659 */
2660 
write(time_t event_time,const char * user_host,uint user_host_len,int thread_id,const char * command_type,uint command_type_len,const char * sql_text,uint sql_text_len)2661 bool MYSQL_QUERY_LOG::write(time_t event_time, const char *user_host,
2662                             uint user_host_len, int thread_id,
2663                             const char *command_type, uint command_type_len,
2664                             const char *sql_text, uint sql_text_len)
2665 {
2666   char buff[32];
2667   uint length= 0;
2668   char local_time_buff[MAX_TIME_SIZE];
2669   struct tm start;
2670   uint time_buff_len= 0;
2671 
2672   mysql_mutex_lock(&LOCK_log);
2673 
2674   /* Test if someone closed between the is_open test and lock */
2675   if (is_open())
2676   {
2677     /* for testing output of timestamp and thread id */
2678     DBUG_EXECUTE_IF("reset_log_last_time", last_time= 0;);
2679 
2680     /* Note that my_b_write() assumes it knows the length for this */
2681       if (event_time != last_time)
2682       {
2683         last_time= event_time;
2684 
2685         localtime_r(&event_time, &start);
2686 
2687         time_buff_len= my_snprintf(local_time_buff, MAX_TIME_SIZE,
2688                                    "%02d%02d%02d %2d:%02d:%02d\t",
2689                                    start.tm_year % 100, start.tm_mon + 1,
2690                                    start.tm_mday, start.tm_hour,
2691                                    start.tm_min, start.tm_sec);
2692 
2693         if (my_b_write(&log_file, (uchar*) local_time_buff, time_buff_len))
2694           goto err;
2695       }
2696       else
2697         if (my_b_write(&log_file, (uchar*) "\t\t" ,2) < 0)
2698           goto err;
2699 
2700       /* command_type, thread_id */
2701       length= my_snprintf(buff, 32, "%5ld ", (long) thread_id);
2702 
2703     if (my_b_write(&log_file, (uchar*) buff, length))
2704       goto err;
2705 
2706     if (my_b_write(&log_file, (uchar*) command_type, command_type_len))
2707       goto err;
2708 
2709     if (my_b_write(&log_file, (uchar*) "\t", 1))
2710       goto err;
2711 
2712     /* sql_text */
2713     if (my_b_write(&log_file, (uchar*) sql_text, sql_text_len))
2714       goto err;
2715 
2716     if (my_b_write(&log_file, (uchar*) "\n", 1) ||
2717         flush_io_cache(&log_file))
2718       goto err;
2719   }
2720 
2721   mysql_mutex_unlock(&LOCK_log);
2722   return FALSE;
2723 err:
2724 
2725   if (!write_error)
2726   {
2727     write_error= 1;
2728     sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
2729   }
2730   mysql_mutex_unlock(&LOCK_log);
2731   return TRUE;
2732 }
2733 
2734 
2735 /*
2736   Log a query to the traditional slow log file
2737 
2738   SYNOPSIS
2739     write()
2740 
2741     thd               THD of the query
2742     current_time      current timestamp
2743     query_start_arg   command start timestamp
2744     user_host         the pointer to the string with user@host info
2745     user_host_len     length of the user_host string. this is computed once
2746                       and passed to all general log event handlers
2747     query_utime       Amount of time the query took to execute (in microseconds)
2748     lock_utime        Amount of time the query was locked (in microseconds)
2749     is_command        The flag, which determines, whether the sql_text is a
2750                       query or an administrator command.
2751     sql_text          the very text of the query or administrator command
2752                       processed
2753     sql_text_len      the length of sql_text string
2754 
2755   DESCRIPTION
2756 
2757    Log a query to the slow log file.
2758 
2759   RETURN
2760     FALSE - OK
2761     TRUE - error occured
2762 */
2763 
write(THD * thd,time_t current_time,time_t query_start_arg,const char * user_host,uint user_host_len,ulonglong query_utime,ulonglong lock_utime,bool is_command,const char * sql_text,uint sql_text_len)2764 bool MYSQL_QUERY_LOG::write(THD *thd, time_t current_time,
2765                             time_t query_start_arg, const char *user_host,
2766                             uint user_host_len, ulonglong query_utime,
2767                             ulonglong lock_utime, bool is_command,
2768                             const char *sql_text, uint sql_text_len)
2769 {
2770   bool error= 0;
2771   DBUG_ENTER("MYSQL_QUERY_LOG::write");
2772 
2773   mysql_mutex_lock(&LOCK_log);
2774 
2775   if (!is_open())
2776   {
2777     mysql_mutex_unlock(&LOCK_log);
2778     DBUG_RETURN(0);
2779   }
2780 
2781   if (is_open())
2782   {						// Safety agains reopen
2783     int tmp_errno= 0;
2784     char buff[80], *end;
2785     char query_time_buff[22+7], lock_time_buff[22+7];
2786     uint buff_len;
2787     end= buff;
2788 
2789     if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
2790     {
2791       if (current_time != last_time)
2792       {
2793         last_time= current_time;
2794         struct tm start;
2795         localtime_r(&current_time, &start);
2796 
2797         buff_len= my_snprintf(buff, sizeof buff,
2798                               "# Time: %02d%02d%02d %2d:%02d:%02d\n",
2799                               start.tm_year % 100, start.tm_mon + 1,
2800                               start.tm_mday, start.tm_hour,
2801                               start.tm_min, start.tm_sec);
2802 
2803         /* Note that my_b_write() assumes it knows the length for this */
2804         if (my_b_write(&log_file, (uchar*) buff, buff_len))
2805           tmp_errno= errno;
2806       }
2807       const uchar uh[]= "# User@Host: ";
2808       if (my_b_write(&log_file, uh, sizeof(uh) - 1))
2809         tmp_errno= errno;
2810       if (my_b_write(&log_file, (uchar*) user_host, user_host_len))
2811         tmp_errno= errno;
2812       if (my_b_write(&log_file, (uchar*) "\n", 1))
2813         tmp_errno= errno;
2814     }
2815     /* For slow query log */
2816     sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0);
2817     sprintf(lock_time_buff,  "%.6f", ulonglong2double(lock_utime)/1000000.0);
2818     if (my_b_printf(&log_file,
2819                     "# Query_time: %s  Lock_time: %s"
2820                     " Rows_sent: %lu  Rows_examined: %lu\n",
2821                     query_time_buff, lock_time_buff,
2822                     (ulong) thd->sent_row_count,
2823                     (ulong) thd->examined_row_count) == (uint) -1)
2824       tmp_errno= errno;
2825     if (thd->db && strcmp(thd->db, db))
2826     {						// Database changed
2827       if (my_b_printf(&log_file,"use %s;\n",thd->db) == (uint) -1)
2828         tmp_errno= errno;
2829       strmov(db,thd->db);
2830     }
2831     if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
2832     {
2833       end=strmov(end, ",last_insert_id=");
2834       end=longlong10_to_str((longlong)
2835                             thd->first_successful_insert_id_in_prev_stmt_for_binlog,
2836                             end, -10);
2837     }
2838     // Save value if we do an insert.
2839     if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
2840     {
2841       if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
2842       {
2843         end=strmov(end,",insert_id=");
2844         end=longlong10_to_str((longlong)
2845                               thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(),
2846                               end, -10);
2847       }
2848     }
2849 
2850     /*
2851       This info used to show up randomly, depending on whether the query
2852       checked the query start time or not. now we always write current
2853       timestamp to the slow log
2854     */
2855     end= strmov(end, ",timestamp=");
2856     end= int10_to_str((long) current_time, end, 10);
2857 
2858     if (end != buff)
2859     {
2860       *end++=';';
2861       *end='\n';
2862       if (my_b_write(&log_file, (uchar*) "SET ", 4) ||
2863           my_b_write(&log_file, (uchar*) buff + 1, (uint) (end-buff)))
2864         tmp_errno= errno;
2865     }
2866     if (is_command)
2867     {
2868       end= strxmov(buff, "# administrator command: ", NullS);
2869       buff_len= (ulong) (end - buff);
2870       DBUG_EXECUTE_IF("simulate_slow_log_write_error",
2871                       {DBUG_SET("+d,simulate_file_write_error");});
2872       if(my_b_write(&log_file, (uchar*) buff, buff_len))
2873         tmp_errno= errno;
2874     }
2875     if (my_b_write(&log_file, (uchar*) sql_text, sql_text_len) ||
2876         my_b_write(&log_file, (uchar*) ";\n",2) ||
2877         flush_io_cache(&log_file))
2878       tmp_errno= errno;
2879     if (tmp_errno)
2880     {
2881       error= 1;
2882       if (! write_error)
2883       {
2884         write_error= 1;
2885         sql_print_error(ER(ER_ERROR_ON_WRITE), name, error);
2886       }
2887     }
2888   }
2889   mysql_mutex_unlock(&LOCK_log);
2890   DBUG_RETURN(error);
2891 }
2892 
2893 
2894 /**
2895   @todo
2896   The following should be using fn_format();  We just need to
2897   first change fn_format() to cut the file name if it's too long.
2898 */
generate_name(const char * log_name,const char * suffix,bool strip_ext,char * buff)2899 const char *MYSQL_LOG::generate_name(const char *log_name,
2900                                       const char *suffix,
2901                                       bool strip_ext, char *buff)
2902 {
2903   if (!log_name || !log_name[0])
2904   {
2905     strmake(buff, pidfile_name, FN_REFLEN - strlen(suffix) - 1);
2906     return (const char *)
2907       fn_format(buff, buff, "", suffix, MYF(MY_REPLACE_EXT|MY_REPLACE_DIR));
2908   }
2909   // get rid of extension if the log is binary to avoid problems
2910   if (strip_ext)
2911   {
2912     char *p= fn_ext(log_name);
2913     uint length= (uint) (p - log_name);
2914     strmake(buff, log_name, min(length, FN_REFLEN-1));
2915     return (const char*)buff;
2916   }
2917   return log_name;
2918 }
2919 
2920 
2921 
MYSQL_BIN_LOG(uint * sync_period)2922 MYSQL_BIN_LOG::MYSQL_BIN_LOG(uint *sync_period)
2923   :bytes_written(0), prepared_xids(0), file_id(1), open_count(1),
2924    need_start_event(TRUE),
2925    sync_period_ptr(sync_period), sync_counter(0),
2926    is_relay_log(0), signal_cnt(0),
2927    description_event_for_exec(0), description_event_for_queue(0)
2928 {
2929   /*
2930     We don't want to initialize locks here as such initialization depends on
2931     safe_mutex (when using safe_mutex) which depends on MY_INIT(), which is
2932     called only in main(). Doing initialization here would make it happen
2933     before main().
2934   */
2935   index_file_name[0] = 0;
2936   bzero((char*) &index_file, sizeof(index_file));
2937   bzero((char*) &purge_index_file, sizeof(purge_index_file));
2938 }
2939 
2940 /* this is called only once */
2941 
cleanup()2942 void MYSQL_BIN_LOG::cleanup()
2943 {
2944   DBUG_ENTER("cleanup");
2945   if (inited)
2946   {
2947     inited= 0;
2948     close(LOG_CLOSE_INDEX|LOG_CLOSE_STOP_EVENT);
2949     delete description_event_for_queue;
2950     delete description_event_for_exec;
2951     mysql_mutex_destroy(&LOCK_log);
2952     mysql_mutex_destroy(&LOCK_index);
2953     mysql_cond_destroy(&update_cond);
2954   }
2955   DBUG_VOID_RETURN;
2956 }
2957 
2958 
2959 /* Init binlog-specific vars */
init(bool no_auto_events_arg,ulong max_size_arg)2960 void MYSQL_BIN_LOG::init(bool no_auto_events_arg, ulong max_size_arg)
2961 {
2962   DBUG_ENTER("MYSQL_BIN_LOG::init");
2963   no_auto_events= no_auto_events_arg;
2964   max_size= max_size_arg;
2965   DBUG_PRINT("info",("max_size: %lu", max_size));
2966   DBUG_VOID_RETURN;
2967 }
2968 
2969 
init_pthread_objects()2970 void MYSQL_BIN_LOG::init_pthread_objects()
2971 {
2972   MYSQL_LOG::init_pthread_objects();
2973   mysql_mutex_init(m_key_LOCK_index, &LOCK_index, MY_MUTEX_INIT_SLOW);
2974   mysql_cond_init(m_key_update_cond, &update_cond, 0);
2975 }
2976 
2977 
open_index_file(const char * index_file_name_arg,const char * log_name,bool need_mutex)2978 bool MYSQL_BIN_LOG::open_index_file(const char *index_file_name_arg,
2979                                     const char *log_name, bool need_mutex)
2980 {
2981   File index_file_nr= -1;
2982   DBUG_ASSERT(!my_b_inited(&index_file));
2983 
2984   /*
2985     First open of this class instance
2986     Create an index file that will hold all file names uses for logging.
2987     Add new entries to the end of it.
2988   */
2989   myf opt= MY_UNPACK_FILENAME;
2990   if (!index_file_name_arg)
2991   {
2992     index_file_name_arg= log_name;    // Use same basename for index file
2993     opt= MY_UNPACK_FILENAME | MY_REPLACE_EXT;
2994   }
2995   fn_format(index_file_name, index_file_name_arg, mysql_data_home,
2996             ".index", opt);
2997   if ((index_file_nr= mysql_file_open(m_key_file_log_index,
2998                                       index_file_name,
2999                                       O_RDWR | O_CREAT | O_BINARY,
3000                                       MYF(MY_WME))) < 0 ||
3001        mysql_file_sync(index_file_nr, MYF(MY_WME)) ||
3002        init_io_cache(&index_file, index_file_nr,
3003                      IO_SIZE, WRITE_CACHE,
3004                      mysql_file_seek(index_file_nr, 0L, MY_SEEK_END, MYF(0)),
3005                                      0, MYF(MY_WME | MY_WAIT_IF_FULL)) ||
3006       DBUG_EVALUATE_IF("fault_injection_openning_index", 1, 0))
3007   {
3008     /*
3009       TODO: all operations creating/deleting the index file or a log, should
3010       call my_sync_dir() or my_sync_dir_by_file() to be durable.
3011       TODO: file creation should be done with mysql_file_create()
3012       not mysql_file_open().
3013     */
3014     if (index_file_nr >= 0)
3015       mysql_file_close(index_file_nr, MYF(0));
3016     return TRUE;
3017   }
3018 
3019 #ifdef HAVE_REPLICATION
3020   /*
3021     Sync the index by purging any binary log file that is not registered.
3022     In other words, either purge binary log files that were removed from
3023     the index but not purged from the file system due to a crash or purge
3024     any binary log file that was created but not register in the index
3025     due to a crash.
3026   */
3027 
3028   if (set_purge_index_file_name(index_file_name_arg) ||
3029       open_purge_index_file(FALSE) ||
3030       purge_index_entry(NULL, NULL, need_mutex) ||
3031       close_purge_index_file() ||
3032       DBUG_EVALUATE_IF("fault_injection_recovering_index", 1, 0))
3033   {
3034     sql_print_error("MYSQL_BIN_LOG::open_index_file failed to sync the index "
3035                     "file.");
3036     return TRUE;
3037   }
3038 #endif
3039 
3040   return FALSE;
3041 }
3042 
3043 
3044 /**
3045   Open a (new) binlog file.
3046 
3047   - Open the log file and the index file. Register the new
3048   file name in it
3049   - When calling this when the file is in use, you must have a locks
3050   on LOCK_log and LOCK_index.
3051 
3052   @retval
3053     0	ok
3054   @retval
3055     1	error
3056 */
3057 
open(const char * log_name,enum_log_type log_type_arg,const char * new_name,enum cache_type io_cache_type_arg,bool no_auto_events_arg,ulong max_size_arg,bool null_created_arg,bool need_mutex)3058 bool MYSQL_BIN_LOG::open(const char *log_name,
3059                          enum_log_type log_type_arg,
3060                          const char *new_name,
3061                          enum cache_type io_cache_type_arg,
3062                          bool no_auto_events_arg,
3063                          ulong max_size_arg,
3064                          bool null_created_arg,
3065                          bool need_mutex)
3066 {
3067   File file= -1;
3068 
3069   DBUG_ENTER("MYSQL_BIN_LOG::open");
3070   DBUG_PRINT("enter",("log_type: %d",(int) log_type_arg));
3071 
3072   if (init_and_set_log_file_name(log_name, new_name, log_type_arg,
3073                                  io_cache_type_arg))
3074   {
3075     sql_print_error("MSYQL_BIN_LOG::open failed to generate new file name.");
3076     DBUG_RETURN(1);
3077   }
3078 
3079 #ifdef HAVE_REPLICATION
3080   if (open_purge_index_file(TRUE) ||
3081       register_create_index_entry(log_file_name) ||
3082       sync_purge_index_file() ||
3083       DBUG_EVALUATE_IF("fault_injection_registering_index", 1, 0))
3084   {
3085     /**
3086         TODO: although this was introduced to appease valgrind
3087               when injecting emulated faults using fault_injection_registering_index
3088               it may be good to consider what actually happens when
3089               open_purge_index_file succeeds but register or sync fails.
3090 
3091               Perhaps we might need the code below in MYSQL_LOG_BIN::cleanup
3092               for "real life" purposes as well?
3093      */
3094     DBUG_EXECUTE_IF("fault_injection_registering_index", {
3095       if (my_b_inited(&purge_index_file))
3096       {
3097         end_io_cache(&purge_index_file);
3098         my_close(purge_index_file.file, MYF(0));
3099       }
3100     });
3101 
3102     sql_print_error("MSYQL_BIN_LOG::open failed to sync the index file.");
3103     DBUG_RETURN(1);
3104   }
3105   DBUG_EXECUTE_IF("crash_create_non_critical_before_update_index", DBUG_SUICIDE(););
3106 #endif
3107 
3108   write_error= 0;
3109 
3110   /* open the main log file */
3111   if (MYSQL_LOG::open(
3112 #ifdef HAVE_PSI_INTERFACE
3113                       m_key_file_log,
3114 #endif
3115                       log_name, log_type_arg, new_name, io_cache_type_arg))
3116   {
3117 #ifdef HAVE_REPLICATION
3118     close_purge_index_file();
3119 #endif
3120     DBUG_RETURN(1);                            /* all warnings issued */
3121   }
3122 
3123   init(no_auto_events_arg, max_size_arg);
3124 
3125   open_count++;
3126 
3127   DBUG_ASSERT(log_type == LOG_BIN);
3128 
3129   {
3130     bool write_file_name_to_index_file=0;
3131 
3132     if (!my_b_filelength(&log_file))
3133     {
3134       /*
3135 	The binary log file was empty (probably newly created)
3136 	This is the normal case and happens when the user doesn't specify
3137 	an extension for the binary log files.
3138 	In this case we write a standard header to it.
3139       */
3140       if (my_b_safe_write(&log_file, (uchar*) BINLOG_MAGIC,
3141 			  BIN_LOG_HEADER_SIZE))
3142         goto err;
3143       bytes_written+= BIN_LOG_HEADER_SIZE;
3144       write_file_name_to_index_file= 1;
3145     }
3146 
3147     if (need_start_event && !no_auto_events)
3148     {
3149       /*
3150         In 4.x we set need_start_event=0 here, but in 5.0 we want a Start event
3151         even if this is not the very first binlog.
3152       */
3153       Format_description_log_event s(BINLOG_VERSION);
3154       /*
3155         don't set LOG_EVENT_BINLOG_IN_USE_F for SEQ_READ_APPEND io_cache
3156         as we won't be able to reset it later
3157       */
3158       if (io_cache_type == WRITE_CACHE)
3159         s.flags|= LOG_EVENT_BINLOG_IN_USE_F;
3160       if (!s.is_valid())
3161         goto err;
3162       s.dont_set_created= null_created_arg;
3163       if (s.write(&log_file))
3164         goto err;
3165       bytes_written+= s.data_written;
3166     }
3167     if (description_event_for_queue &&
3168         description_event_for_queue->binlog_version>=4)
3169     {
3170       /*
3171         This is a relay log written to by the I/O slave thread.
3172         Write the event so that others can later know the format of this relay
3173         log.
3174         Note that this event is very close to the original event from the
3175         master (it has binlog version of the master, event types of the
3176         master), so this is suitable to parse the next relay log's event. It
3177         has been produced by
3178         Format_description_log_event::Format_description_log_event(char* buf,).
3179         Why don't we want to write the description_event_for_queue if this
3180         event is for format<4 (3.23 or 4.x): this is because in that case, the
3181         description_event_for_queue describes the data received from the
3182         master, but not the data written to the relay log (*conversion*),
3183         which is in format 4 (slave's).
3184       */
3185       /*
3186         Set 'created' to 0, so that in next relay logs this event does not
3187         trigger cleaning actions on the slave in
3188         Format_description_log_event::apply_event_impl().
3189       */
3190       description_event_for_queue->created= 0;
3191       /* Don't set log_pos in event header */
3192       description_event_for_queue->set_artificial_event();
3193 
3194       if (description_event_for_queue->write(&log_file))
3195         goto err;
3196       bytes_written+= description_event_for_queue->data_written;
3197     }
3198     if (flush_io_cache(&log_file) ||
3199         mysql_file_sync(log_file.file, MYF(MY_WME)))
3200       goto err;
3201 
3202     if (write_file_name_to_index_file)
3203     {
3204 #ifdef HAVE_REPLICATION
3205       DBUG_EXECUTE_IF("crash_create_critical_before_update_index", DBUG_SUICIDE(););
3206 #endif
3207 
3208       DBUG_ASSERT(my_b_inited(&index_file) != 0);
3209       reinit_io_cache(&index_file, WRITE_CACHE,
3210                       my_b_filelength(&index_file), 0, 0);
3211       /*
3212         As this is a new log file, we write the file name to the index
3213         file. As every time we write to the index file, we sync it.
3214       */
3215       if (DBUG_EVALUATE_IF("fault_injection_updating_index", 1, 0) ||
3216           my_b_write(&index_file, (uchar*) log_file_name,
3217                      strlen(log_file_name)) ||
3218           my_b_write(&index_file, (uchar*) "\n", 1) ||
3219           flush_io_cache(&index_file) ||
3220           mysql_file_sync(index_file.file, MYF(MY_WME)))
3221         goto err;
3222 
3223 #ifdef HAVE_REPLICATION
3224       DBUG_EXECUTE_IF("crash_create_after_update_index", DBUG_SUICIDE(););
3225 #endif
3226     }
3227   }
3228   log_state= LOG_OPENED;
3229 
3230 #ifdef HAVE_REPLICATION
3231   close_purge_index_file();
3232 #endif
3233 
3234   DBUG_RETURN(0);
3235 
3236 err:
3237 #ifdef HAVE_REPLICATION
3238   if (is_inited_purge_index_file())
3239     purge_index_entry(NULL, NULL, need_mutex);
3240   close_purge_index_file();
3241 #endif
3242   sql_print_error("Could not use %s for logging (error %d). \
3243 Turning logging off for the whole duration of the MySQL server process. \
3244 To turn it on again: fix the cause, \
3245 shutdown the MySQL server and restart it.", name, errno);
3246   if (file >= 0)
3247     mysql_file_close(file, MYF(0));
3248   end_io_cache(&log_file);
3249   end_io_cache(&index_file);
3250   my_free(name);
3251   name= NULL;
3252   log_state= LOG_CLOSED;
3253   DBUG_RETURN(1);
3254 }
3255 
3256 
get_current_log(LOG_INFO * linfo)3257 int MYSQL_BIN_LOG::get_current_log(LOG_INFO* linfo)
3258 {
3259   mysql_mutex_lock(&LOCK_log);
3260   int ret = raw_get_current_log(linfo);
3261   mysql_mutex_unlock(&LOCK_log);
3262   return ret;
3263 }
3264 
raw_get_current_log(LOG_INFO * linfo)3265 int MYSQL_BIN_LOG::raw_get_current_log(LOG_INFO* linfo)
3266 {
3267   strmake(linfo->log_file_name, log_file_name, sizeof(linfo->log_file_name)-1);
3268   linfo->pos = my_b_tell(&log_file);
3269   return 0;
3270 }
3271 
3272 /**
3273   Move all data up in a file in an filename index file.
3274 
3275     We do the copy outside of the IO_CACHE as the cache buffers would just
3276     make things slower and more complicated.
3277     In most cases the copy loop should only do one read.
3278 
3279   @param index_file			File to move
3280   @param offset			Move everything from here to beginning
3281 
3282   @note
3283     File will be truncated to be 'offset' shorter or filled up with newlines
3284 
3285   @retval
3286     0	ok
3287 */
3288 
3289 #ifdef HAVE_REPLICATION
3290 
copy_up_file_and_fill(IO_CACHE * index_file,my_off_t offset)3291 static bool copy_up_file_and_fill(IO_CACHE *index_file, my_off_t offset)
3292 {
3293   int bytes_read;
3294   my_off_t init_offset= offset;
3295   File file= index_file->file;
3296   uchar io_buf[IO_SIZE*2];
3297   DBUG_ENTER("copy_up_file_and_fill");
3298 
3299   for (;; offset+= bytes_read)
3300   {
3301     mysql_file_seek(file, offset, MY_SEEK_SET, MYF(0));
3302     if ((bytes_read= (int) mysql_file_read(file, io_buf, sizeof(io_buf),
3303                                            MYF(MY_WME)))
3304 	< 0)
3305       goto err;
3306     if (!bytes_read)
3307       break;					// end of file
3308     mysql_file_seek(file, offset-init_offset, MY_SEEK_SET, MYF(0));
3309     if (mysql_file_write(file, io_buf, bytes_read, MYF(MY_WME | MY_NABP)))
3310       goto err;
3311   }
3312   /* The following will either truncate the file or fill the end with \n' */
3313   if (mysql_file_chsize(file, offset - init_offset, '\n', MYF(MY_WME)) ||
3314       mysql_file_sync(file, MYF(MY_WME)))
3315     goto err;
3316 
3317   /* Reset data in old index cache */
3318   reinit_io_cache(index_file, READ_CACHE, (my_off_t) 0, 0, 1);
3319   DBUG_RETURN(0);
3320 
3321 err:
3322   DBUG_RETURN(1);
3323 }
3324 
3325 #endif /* HAVE_REPLICATION */
3326 
3327 /**
3328   Find the position in the log-index-file for the given log name.
3329 
3330   @param linfo		Store here the found log file name and position to
3331                        the NEXT log file name in the index file.
3332   @param log_name	Filename to find in the index file.
3333                        Is a null pointer if we want to read the first entry
3334   @param need_lock	Set this to 1 if the parent doesn't already have a
3335                        lock on LOCK_index
3336 
3337   @note
3338     On systems without the truncate function the file will end with one or
3339     more empty lines.  These will be ignored when reading the file.
3340 
3341   @retval
3342     0			ok
3343   @retval
3344     LOG_INFO_EOF	        End of log-index-file found
3345   @retval
3346     LOG_INFO_IO		Got IO error while reading file
3347 */
3348 
find_log_pos(LOG_INFO * linfo,const char * log_name,bool need_lock)3349 int MYSQL_BIN_LOG::find_log_pos(LOG_INFO *linfo, const char *log_name,
3350 			    bool need_lock)
3351 {
3352   int error= 0;
3353   char *full_fname= linfo->log_file_name;
3354   char full_log_name[FN_REFLEN], fname[FN_REFLEN];
3355   uint log_name_len= 0, fname_len= 0;
3356   DBUG_ENTER("find_log_pos");
3357   full_log_name[0]= full_fname[0]= 0;
3358 
3359   /*
3360     Mutex needed because we need to make sure the file pointer does not
3361     move from under our feet
3362   */
3363   if (need_lock)
3364     mysql_mutex_lock(&LOCK_index);
3365   mysql_mutex_assert_owner(&LOCK_index);
3366 
3367   // extend relative paths for log_name to be searched
3368   if (log_name)
3369   {
3370     if(normalize_binlog_name(full_log_name, log_name, is_relay_log))
3371     {
3372       error= LOG_INFO_EOF;
3373       goto end;
3374     }
3375   }
3376 
3377   log_name_len= log_name ? (uint) strlen(full_log_name) : 0;
3378   DBUG_PRINT("enter", ("log_name: %s, full_log_name: %s",
3379                        log_name ? log_name : "NULL", full_log_name));
3380 
3381   /* As the file is flushed, we can't get an error here */
3382   (void) reinit_io_cache(&index_file, READ_CACHE, (my_off_t) 0, 0, 0);
3383 
3384   for (;;)
3385   {
3386     uint length;
3387     my_off_t offset= my_b_tell(&index_file);
3388 
3389     DBUG_EXECUTE_IF("simulate_find_log_pos_error",
3390                     error=  LOG_INFO_EOF; break;);
3391     /* If we get 0 or 1 characters, this is the end of the file */
3392     if ((length= my_b_gets(&index_file, fname, FN_REFLEN)) <= 1)
3393     {
3394       /* Did not find the given entry; Return not found or error */
3395       error= !index_file.error ? LOG_INFO_EOF : LOG_INFO_IO;
3396       break;
3397     }
3398 
3399     // extend relative paths and match against full path
3400     if (normalize_binlog_name(full_fname, fname, is_relay_log))
3401     {
3402       error= LOG_INFO_EOF;
3403       break;
3404     }
3405     fname_len= (uint) strlen(full_fname);
3406 
3407     // if the log entry matches, null string matching anything
3408     if (!log_name ||
3409 	(log_name_len == fname_len-1 && full_fname[log_name_len] == '\n' &&
3410 	 !memcmp(full_fname, full_log_name, log_name_len)))
3411     {
3412       DBUG_PRINT("info", ("Found log file entry"));
3413       full_fname[fname_len-1]= 0;			// remove last \n
3414       linfo->index_file_start_offset= offset;
3415       linfo->index_file_offset = my_b_tell(&index_file);
3416       break;
3417     }
3418   }
3419 
3420 end:
3421   if (need_lock)
3422     mysql_mutex_unlock(&LOCK_index);
3423   DBUG_RETURN(error);
3424 }
3425 
3426 
3427 /**
3428   Find the position in the log-index-file for the given log name.
3429 
3430   @param
3431     linfo		Store here the next log file name and position to
3432 			the file name after that.
3433   @param
3434     need_lock		Set this to 1 if the parent doesn't already have a
3435 			lock on LOCK_index
3436 
3437   @note
3438     - Before calling this function, one has to call find_log_pos()
3439     to set up 'linfo'
3440     - Mutex needed because we need to make sure the file pointer does not move
3441     from under our feet
3442 
3443   @retval
3444     0			ok
3445   @retval
3446     LOG_INFO_EOF	        End of log-index-file found
3447   @retval
3448     LOG_INFO_IO		Got IO error while reading file
3449 */
3450 
find_next_log(LOG_INFO * linfo,bool need_lock)3451 int MYSQL_BIN_LOG::find_next_log(LOG_INFO* linfo, bool need_lock)
3452 {
3453   int error= 0;
3454   uint length;
3455   char fname[FN_REFLEN];
3456   char *full_fname= linfo->log_file_name;
3457 
3458   if (need_lock)
3459     mysql_mutex_lock(&LOCK_index);
3460   mysql_mutex_assert_owner(&LOCK_index);
3461 
3462   /* As the file is flushed, we can't get an error here */
3463   (void) reinit_io_cache(&index_file, READ_CACHE, linfo->index_file_offset, 0,
3464 			 0);
3465 
3466   linfo->index_file_start_offset= linfo->index_file_offset;
3467   if ((length=my_b_gets(&index_file, fname, FN_REFLEN)) <= 1)
3468   {
3469     error = !index_file.error ? LOG_INFO_EOF : LOG_INFO_IO;
3470     goto err;
3471   }
3472 
3473   if (fname[0] != 0)
3474   {
3475     if(normalize_binlog_name(full_fname, fname, is_relay_log))
3476     {
3477       error= LOG_INFO_EOF;
3478       goto err;
3479     }
3480     length= strlen(full_fname);
3481   }
3482 
3483   full_fname[length-1]= 0;			// kill \n
3484   linfo->index_file_offset= my_b_tell(&index_file);
3485 
3486 err:
3487   if (need_lock)
3488     mysql_mutex_unlock(&LOCK_index);
3489   return error;
3490 }
3491 
3492 
3493 /**
3494   Delete all logs refered to in the index file.
3495   Start writing to a new log file.
3496 
3497   The new index file will only contain this file.
3498 
3499   @param thd		Thread
3500 
3501   @note
3502     If not called from slave thread, write start event to new log
3503 
3504   @retval
3505     0	ok
3506   @retval
3507     1   error
3508 */
3509 
reset_logs(THD * thd)3510 bool MYSQL_BIN_LOG::reset_logs(THD* thd)
3511 {
3512   LOG_INFO linfo;
3513   bool error=0;
3514   int err;
3515   const char* save_name;
3516   DBUG_ENTER("reset_logs");
3517 
3518   ha_reset_logs(thd);
3519 
3520   /*
3521     We need to get both locks to be sure that no one is trying to
3522     write to the index log file.
3523   */
3524   mysql_mutex_lock(&LOCK_log);
3525   mysql_mutex_lock(&LOCK_index);
3526 
3527   /*
3528     The following mutex is needed to ensure that no threads call
3529     'delete thd' as we would then risk missing a 'rollback' from this
3530     thread. If the transaction involved MyISAM tables, it should go
3531     into binlog even on rollback.
3532   */
3533   mysql_mutex_lock(&LOCK_thread_count);
3534 
3535   /* Save variables so that we can reopen the log */
3536   save_name=name;
3537   name=0;					// Protect against free
3538   close(LOG_CLOSE_TO_BE_OPENED);
3539 
3540   /*
3541     First delete all old log files and then update the index file.
3542     As we first delete the log files and do not use sort of logging,
3543     a crash may lead to an inconsistent state where the index has
3544     references to non-existent files.
3545 
3546     We need to invert the steps and use the purge_index_file methods
3547     in order to make the operation safe.
3548   */
3549 
3550   if ((err= find_log_pos(&linfo, NullS, 0)) != 0)
3551   {
3552     uint errcode= purge_log_get_error_code(err);
3553     sql_print_error("Failed to locate old binlog or relay log files");
3554     my_message(errcode, ER(errcode), MYF(0));
3555     error= 1;
3556     goto err;
3557   }
3558 
3559   for (;;)
3560   {
3561     if ((error= my_delete_allow_opened(linfo.log_file_name, MYF(0))) != 0)
3562     {
3563       if (my_errno == ENOENT)
3564       {
3565         push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3566                             ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
3567                             linfo.log_file_name);
3568         sql_print_information("Failed to delete file '%s'",
3569                               linfo.log_file_name);
3570         my_errno= 0;
3571         error= 0;
3572       }
3573       else
3574       {
3575         push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3576                             ER_BINLOG_PURGE_FATAL_ERR,
3577                             "a problem with deleting %s; "
3578                             "consider examining correspondence "
3579                             "of your binlog index file "
3580                             "to the actual binlog files",
3581                             linfo.log_file_name);
3582         error= 1;
3583         goto err;
3584       }
3585     }
3586     if (find_next_log(&linfo, 0))
3587       break;
3588   }
3589 
3590   /* Start logging with a new file */
3591   close(LOG_CLOSE_INDEX | LOG_CLOSE_TO_BE_OPENED);
3592   if ((error= my_delete_allow_opened(index_file_name, MYF(0))))	// Reset (open will update)
3593   {
3594     if (my_errno == ENOENT)
3595     {
3596       push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3597                           ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
3598                           index_file_name);
3599       sql_print_information("Failed to delete file '%s'",
3600                             index_file_name);
3601       my_errno= 0;
3602       error= 0;
3603     }
3604     else
3605     {
3606       push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3607                           ER_BINLOG_PURGE_FATAL_ERR,
3608                           "a problem with deleting %s; "
3609                           "consider examining correspondence "
3610                           "of your binlog index file "
3611                           "to the actual binlog files",
3612                           index_file_name);
3613       error= 1;
3614       goto err;
3615     }
3616   }
3617   if (!thd->slave_thread)
3618     need_start_event=1;
3619   if (!open_index_file(index_file_name, 0, FALSE))
3620     if ((error= open(save_name, log_type, 0, io_cache_type, no_auto_events, max_size, 0, FALSE)))
3621       goto err;
3622   my_free((void *) save_name);
3623 
3624 err:
3625   if (error == 1)
3626     name= const_cast<char*>(save_name);
3627   mysql_mutex_unlock(&LOCK_thread_count);
3628   mysql_mutex_unlock(&LOCK_index);
3629   mysql_mutex_unlock(&LOCK_log);
3630   DBUG_RETURN(error);
3631 }
3632 
3633 
3634 /**
3635   Delete relay log files prior to rli->group_relay_log_name
3636   (i.e. all logs which are not involved in a non-finished group
3637   (transaction)), remove them from the index file and start on next
3638   relay log.
3639 
3640   IMPLEMENTATION
3641   - Protects index file with LOCK_index
3642   - Delete relevant relay log files
3643   - Copy all file names after these ones to the front of the index file
3644   - If the OS has truncate, truncate the file, else fill it with \n'
3645   - Read the next file name from the index file and store in rli->linfo
3646 
3647   @param rli	       Relay log information
3648   @param included     If false, all relay logs that are strictly before
3649                       rli->group_relay_log_name are deleted ; if true, the
3650                       latter is deleted too (i.e. all relay logs
3651                       read by the SQL slave thread are deleted).
3652 
3653   @note
3654     - This is only called from the slave-execute thread when it has read
3655     all commands from a relay log and want to switch to a new relay log.
3656     - When this happens, we can be in an active transaction as
3657     a transaction can span over two relay logs
3658     (although it is always written as a single block to the master's binary
3659     log, hence cannot span over two master's binary logs).
3660 
3661   @retval
3662     0			ok
3663   @retval
3664     LOG_INFO_EOF	        End of log-index-file found
3665   @retval
3666     LOG_INFO_SEEK	Could not allocate IO cache
3667   @retval
3668     LOG_INFO_IO		Got IO error while reading file
3669 */
3670 
3671 #ifdef HAVE_REPLICATION
3672 
purge_first_log(Relay_log_info * rli,bool included)3673 int MYSQL_BIN_LOG::purge_first_log(Relay_log_info* rli, bool included)
3674 {
3675   int error;
3676   char *to_purge_if_included= NULL;
3677   DBUG_ENTER("purge_first_log");
3678 
3679   DBUG_ASSERT(is_open());
3680   DBUG_ASSERT(rli->slave_running == 1);
3681   DBUG_ASSERT(!strcmp(rli->linfo.log_file_name,rli->event_relay_log_name));
3682 
3683   mysql_mutex_lock(&LOCK_index);
3684   to_purge_if_included= my_strdup(rli->group_relay_log_name, MYF(0));
3685 
3686   /*
3687     Read the next log file name from the index file and pass it back to
3688     the caller.
3689   */
3690   if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0)) ||
3691      (error=find_next_log(&rli->linfo, 0)))
3692   {
3693     char buff[22];
3694     sql_print_error("next log error: %d  offset: %s  log: %s included: %d",
3695                     error,
3696                     llstr(rli->linfo.index_file_offset,buff),
3697                     rli->event_relay_log_name,
3698                     included);
3699     goto err;
3700   }
3701 
3702   /*
3703     Reset rli's coordinates to the current log.
3704   */
3705   rli->event_relay_log_pos= BIN_LOG_HEADER_SIZE;
3706   strmake(rli->event_relay_log_name,rli->linfo.log_file_name,
3707 	  sizeof(rli->event_relay_log_name)-1);
3708 
3709   /*
3710     If we removed the rli->group_relay_log_name file,
3711     we must update the rli->group* coordinates, otherwise do not touch it as the
3712     group's execution is not finished (e.g. COMMIT not executed)
3713   */
3714   if (included)
3715   {
3716     rli->group_relay_log_pos = BIN_LOG_HEADER_SIZE;
3717     strmake(rli->group_relay_log_name,rli->linfo.log_file_name,
3718             sizeof(rli->group_relay_log_name)-1);
3719     rli->notify_group_relay_log_name_update();
3720   }
3721 
3722   /* Store where we are in the new file for the execution thread */
3723   flush_relay_log_info(rli);
3724 
3725   DBUG_EXECUTE_IF("crash_before_purge_logs", DBUG_SUICIDE(););
3726 
3727   mysql_mutex_lock(&rli->log_space_lock);
3728   rli->relay_log.purge_logs(to_purge_if_included, included,
3729                             0, 0, &rli->log_space_total);
3730   mysql_mutex_unlock(&rli->log_space_lock);
3731 
3732   /*
3733     Ok to broadcast after the critical region as there is no risk of
3734     the mutex being destroyed by this thread later - this helps save
3735     context switches
3736   */
3737   mysql_cond_broadcast(&rli->log_space_cond);
3738 
3739   /*
3740    * Need to update the log pos because purge logs has been called
3741    * after fetching initially the log pos at the begining of the method.
3742    */
3743   if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0)))
3744   {
3745     char buff[22];
3746     sql_print_error("next log error: %d  offset: %s  log: %s included: %d",
3747                     error,
3748                     llstr(rli->linfo.index_file_offset,buff),
3749                     rli->group_relay_log_name,
3750                     included);
3751     goto err;
3752   }
3753 
3754   /* If included was passed, rli->linfo should be the first entry. */
3755   DBUG_ASSERT(!included || rli->linfo.index_file_start_offset == 0);
3756 
3757 err:
3758   my_free(to_purge_if_included);
3759   mysql_mutex_unlock(&LOCK_index);
3760   DBUG_RETURN(error);
3761 }
3762 
3763 /**
3764   Update log index_file.
3765 */
3766 
update_log_index(LOG_INFO * log_info,bool need_update_threads)3767 int MYSQL_BIN_LOG::update_log_index(LOG_INFO* log_info, bool need_update_threads)
3768 {
3769   if (copy_up_file_and_fill(&index_file, log_info->index_file_start_offset))
3770     return LOG_INFO_IO;
3771 
3772   // now update offsets in index file for running threads
3773   if (need_update_threads)
3774     adjust_linfo_offsets(log_info->index_file_start_offset);
3775   return 0;
3776 }
3777 
3778 /**
3779   Remove all logs before the given log from disk and from the index file.
3780 
3781   @param to_log	      Delete all log file name before this file.
3782   @param included            If true, to_log is deleted too.
3783   @param need_mutex
3784   @param need_update_threads If we want to update the log coordinates of
3785                              all threads. False for relay logs, true otherwise.
3786   @param freed_log_space     If not null, decrement this variable of
3787                              the amount of log space freed
3788 
3789   @note
3790     If any of the logs before the deleted one is in use,
3791     only purge logs up to this one.
3792 
3793   @retval
3794     0			ok
3795   @retval
3796     LOG_INFO_EOF		to_log not found
3797     LOG_INFO_EMFILE             too many files opened
3798     LOG_INFO_FATAL              if any other than ENOENT error from
3799                                 mysql_file_stat() or mysql_file_delete()
3800 */
3801 
purge_logs(const char * to_log,bool included,bool need_mutex,bool need_update_threads,ulonglong * decrease_log_space)3802 int MYSQL_BIN_LOG::purge_logs(const char *to_log,
3803                           bool included,
3804                           bool need_mutex,
3805                           bool need_update_threads,
3806                           ulonglong *decrease_log_space)
3807 {
3808   int error= 0;
3809   bool exit_loop= 0;
3810   LOG_INFO log_info;
3811   THD *thd= current_thd;
3812   DBUG_ENTER("purge_logs");
3813   DBUG_PRINT("info",("to_log= %s",to_log));
3814 
3815   if (need_mutex)
3816     mysql_mutex_lock(&LOCK_index);
3817   if ((error=find_log_pos(&log_info, to_log, 0 /*no mutex*/)))
3818   {
3819     sql_print_error("MYSQL_BIN_LOG::purge_logs was called with file %s not "
3820                     "listed in the index.", to_log);
3821     goto err;
3822   }
3823 
3824   if ((error= open_purge_index_file(TRUE)))
3825   {
3826     sql_print_error("MYSQL_BIN_LOG::purge_logs failed to sync the index file.");
3827     goto err;
3828   }
3829 
3830   /*
3831     File name exists in index file; delete until we find this file
3832     or a file that is used.
3833   */
3834   if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/)))
3835     goto err;
3836   while ((strcmp(to_log,log_info.log_file_name) || (exit_loop=included)) &&
3837          !is_active(log_info.log_file_name) &&
3838          !log_in_use(log_info.log_file_name))
3839   {
3840     if ((error= register_purge_index_entry(log_info.log_file_name)))
3841     {
3842       sql_print_error("MYSQL_BIN_LOG::purge_logs failed to copy %s to register file.",
3843                       log_info.log_file_name);
3844       goto err;
3845     }
3846 
3847     if (find_next_log(&log_info, 0) || exit_loop)
3848       break;
3849   }
3850 
3851   DBUG_EXECUTE_IF("crash_purge_before_update_index", DBUG_SUICIDE(););
3852 
3853   if ((error= sync_purge_index_file()))
3854   {
3855     sql_print_error("MSYQL_BIN_LOG::purge_logs failed to flush register file.");
3856     goto err;
3857   }
3858 
3859   /* We know how many files to delete. Update index file. */
3860   if ((error=update_log_index(&log_info, need_update_threads)))
3861   {
3862     sql_print_error("MSYQL_BIN_LOG::purge_logs failed to update the index file");
3863     goto err;
3864   }
3865 
3866   DBUG_EXECUTE_IF("crash_purge_critical_after_update_index", DBUG_SUICIDE(););
3867 
3868 err:
3869   /* Read each entry from purge_index_file and delete the file. */
3870   if (is_inited_purge_index_file() &&
3871       (error= purge_index_entry(thd, decrease_log_space, FALSE)))
3872     sql_print_error("MSYQL_BIN_LOG::purge_logs failed to process registered files"
3873                     " that would be purged.");
3874   close_purge_index_file();
3875 
3876   DBUG_EXECUTE_IF("crash_purge_non_critical_after_update_index", DBUG_SUICIDE(););
3877 
3878   if (need_mutex)
3879     mysql_mutex_unlock(&LOCK_index);
3880   DBUG_RETURN(error);
3881 }
3882 
set_purge_index_file_name(const char * base_file_name)3883 int MYSQL_BIN_LOG::set_purge_index_file_name(const char *base_file_name)
3884 {
3885   int error= 0;
3886   DBUG_ENTER("MYSQL_BIN_LOG::set_purge_index_file_name");
3887   if (fn_format(purge_index_file_name, base_file_name, mysql_data_home,
3888                 ".~rec~", MYF(MY_UNPACK_FILENAME | MY_SAFE_PATH |
3889                               MY_REPLACE_EXT)) == NULL)
3890   {
3891     error= 1;
3892     sql_print_error("MYSQL_BIN_LOG::set_purge_index_file_name failed to set "
3893                       "file name.");
3894   }
3895   DBUG_RETURN(error);
3896 }
3897 
open_purge_index_file(bool destroy)3898 int MYSQL_BIN_LOG::open_purge_index_file(bool destroy)
3899 {
3900   int error= 0;
3901   File file= -1;
3902 
3903   DBUG_ENTER("MYSQL_BIN_LOG::open_purge_index_file");
3904 
3905   if (destroy)
3906     close_purge_index_file();
3907 
3908   if (!my_b_inited(&purge_index_file))
3909   {
3910     if ((file= my_open(purge_index_file_name, O_RDWR | O_CREAT | O_BINARY,
3911                        MYF(MY_WME | ME_WAITTANG))) < 0  ||
3912         init_io_cache(&purge_index_file, file, IO_SIZE,
3913                       (destroy ? WRITE_CACHE : READ_CACHE),
3914                       0, 0, MYF(MY_WME | MY_NABP | MY_WAIT_IF_FULL)))
3915     {
3916       error= 1;
3917       sql_print_error("MYSQL_BIN_LOG::open_purge_index_file failed to open register "
3918                       " file.");
3919     }
3920   }
3921   DBUG_RETURN(error);
3922 }
3923 
close_purge_index_file()3924 int MYSQL_BIN_LOG::close_purge_index_file()
3925 {
3926   int error= 0;
3927 
3928   DBUG_ENTER("MYSQL_BIN_LOG::close_purge_index_file");
3929 
3930   if (my_b_inited(&purge_index_file))
3931   {
3932     end_io_cache(&purge_index_file);
3933     error= my_close(purge_index_file.file, MYF(0));
3934   }
3935   my_delete(purge_index_file_name, MYF(0));
3936   bzero((char*) &purge_index_file, sizeof(purge_index_file));
3937 
3938   DBUG_RETURN(error);
3939 }
3940 
is_inited_purge_index_file()3941 bool MYSQL_BIN_LOG::is_inited_purge_index_file()
3942 {
3943   DBUG_ENTER("MYSQL_BIN_LOG::is_inited_purge_index_file");
3944   DBUG_RETURN (my_b_inited(&purge_index_file));
3945 }
3946 
sync_purge_index_file()3947 int MYSQL_BIN_LOG::sync_purge_index_file()
3948 {
3949   int error= 0;
3950   DBUG_ENTER("MYSQL_BIN_LOG::sync_purge_index_file");
3951 
3952   if ((error= flush_io_cache(&purge_index_file)) ||
3953       (error= my_sync(purge_index_file.file, MYF(MY_WME))))
3954     DBUG_RETURN(error);
3955 
3956   DBUG_RETURN(error);
3957 }
3958 
register_purge_index_entry(const char * entry)3959 int MYSQL_BIN_LOG::register_purge_index_entry(const char *entry)
3960 {
3961   int error= 0;
3962   DBUG_ENTER("MYSQL_BIN_LOG::register_purge_index_entry");
3963 
3964   if ((error=my_b_write(&purge_index_file, (const uchar*)entry, strlen(entry))) ||
3965       (error=my_b_write(&purge_index_file, (const uchar*)"\n", 1)))
3966     DBUG_RETURN (error);
3967 
3968   DBUG_RETURN(error);
3969 }
3970 
register_create_index_entry(const char * entry)3971 int MYSQL_BIN_LOG::register_create_index_entry(const char *entry)
3972 {
3973   DBUG_ENTER("MYSQL_BIN_LOG::register_create_index_entry");
3974   DBUG_RETURN(register_purge_index_entry(entry));
3975 }
3976 
purge_index_entry(THD * thd,ulonglong * decrease_log_space,bool need_mutex)3977 int MYSQL_BIN_LOG::purge_index_entry(THD *thd, ulonglong *decrease_log_space,
3978                                      bool need_mutex)
3979 {
3980   MY_STAT s;
3981   int error= 0;
3982   LOG_INFO log_info;
3983   LOG_INFO check_log_info;
3984 
3985   DBUG_ENTER("MYSQL_BIN_LOG:purge_index_entry");
3986 
3987   DBUG_ASSERT(my_b_inited(&purge_index_file));
3988 
3989   if ((error=reinit_io_cache(&purge_index_file, READ_CACHE, 0, 0, 0)))
3990   {
3991     sql_print_error("MSYQL_BIN_LOG::purge_index_entry failed to reinit register file "
3992                     "for read");
3993     goto err;
3994   }
3995 
3996   for (;;)
3997   {
3998     uint length;
3999 
4000     if ((length=my_b_gets(&purge_index_file, log_info.log_file_name,
4001                           FN_REFLEN)) <= 1)
4002     {
4003       if (purge_index_file.error)
4004       {
4005         error= purge_index_file.error;
4006         sql_print_error("MSYQL_BIN_LOG::purge_index_entry error %d reading from "
4007                         "register file.", error);
4008         goto err;
4009       }
4010 
4011       /* Reached EOF */
4012       break;
4013     }
4014 
4015     /* Get rid of the trailing '\n' */
4016     log_info.log_file_name[length-1]= 0;
4017 
4018     if (!mysql_file_stat(m_key_file_log, log_info.log_file_name, &s, MYF(0)))
4019     {
4020       if (my_errno == ENOENT)
4021       {
4022         /*
4023           It's not fatal if we can't stat a log file that does not exist;
4024           If we could not stat, we won't delete.
4025         */
4026         if (thd)
4027         {
4028           push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4029                               ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
4030                               log_info.log_file_name);
4031         }
4032         sql_print_information("Failed to execute mysql_file_stat on file '%s'",
4033 			      log_info.log_file_name);
4034         my_errno= 0;
4035       }
4036       else
4037       {
4038         /*
4039           Other than ENOENT are fatal
4040         */
4041         if (thd)
4042         {
4043           push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4044                               ER_BINLOG_PURGE_FATAL_ERR,
4045                               "a problem with getting info on being purged %s; "
4046                               "consider examining correspondence "
4047                               "of your binlog index file "
4048                               "to the actual binlog files",
4049                               log_info.log_file_name);
4050         }
4051         else
4052         {
4053           sql_print_information("Failed to delete log file '%s'; "
4054                                 "consider examining correspondence "
4055                                 "of your binlog index file "
4056                                 "to the actual binlog files",
4057                                 log_info.log_file_name);
4058         }
4059         error= LOG_INFO_FATAL;
4060         goto err;
4061       }
4062     }
4063     else
4064     {
4065       if ((error= find_log_pos(&check_log_info, log_info.log_file_name, need_mutex)))
4066       {
4067         if (error != LOG_INFO_EOF)
4068         {
4069           if (thd)
4070           {
4071             push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4072                                 ER_BINLOG_PURGE_FATAL_ERR,
4073                                 "a problem with deleting %s and "
4074                                 "reading the binlog index file",
4075                                 log_info.log_file_name);
4076           }
4077           else
4078           {
4079             sql_print_information("Failed to delete file '%s' and "
4080                                   "read the binlog index file",
4081                                   log_info.log_file_name);
4082           }
4083           goto err;
4084         }
4085 
4086         error= 0;
4087         if (!need_mutex)
4088         {
4089           /*
4090             This is to avoid triggering an error in NDB.
4091           */
4092           ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
4093         }
4094 
4095         DBUG_PRINT("info",("purging %s",log_info.log_file_name));
4096         if (!my_delete(log_info.log_file_name, MYF(0)))
4097         {
4098           if (decrease_log_space)
4099             *decrease_log_space-= s.st_size;
4100         }
4101         else
4102         {
4103           if (my_errno == ENOENT)
4104           {
4105             if (thd)
4106             {
4107               push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4108                                   ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
4109                                   log_info.log_file_name);
4110             }
4111             sql_print_information("Failed to delete file '%s'",
4112                                   log_info.log_file_name);
4113             my_errno= 0;
4114           }
4115           else
4116           {
4117             if (thd)
4118             {
4119               push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4120                                   ER_BINLOG_PURGE_FATAL_ERR,
4121                                   "a problem with deleting %s; "
4122                                   "consider examining correspondence "
4123                                   "of your binlog index file "
4124                                   "to the actual binlog files",
4125                                   log_info.log_file_name);
4126             }
4127             else
4128             {
4129               sql_print_information("Failed to delete file '%s'; "
4130                                     "consider examining correspondence "
4131                                     "of your binlog index file "
4132                                     "to the actual binlog files",
4133                                     log_info.log_file_name);
4134             }
4135             if (my_errno == EMFILE)
4136             {
4137               DBUG_PRINT("info",
4138                          ("my_errno: %d, set ret = LOG_INFO_EMFILE", my_errno));
4139               error= LOG_INFO_EMFILE;
4140               goto err;
4141             }
4142             error= LOG_INFO_FATAL;
4143             goto err;
4144           }
4145         }
4146       }
4147     }
4148   }
4149 
4150 err:
4151   DBUG_RETURN(error);
4152 }
4153 
4154 /**
4155   Remove all logs before the given file date from disk and from the
4156   index file.
4157 
4158   @param thd		Thread pointer
4159   @param purge_time	Delete all log files before given date.
4160 
4161   @note
4162     If any of the logs before the deleted one is in use,
4163     only purge logs up to this one.
4164 
4165   @retval
4166     0				ok
4167   @retval
4168     LOG_INFO_PURGE_NO_ROTATE	Binary file that can't be rotated
4169     LOG_INFO_FATAL              if any other than ENOENT error from
4170                                 mysql_file_stat() or mysql_file_delete()
4171 */
4172 
purge_logs_before_date(time_t purge_time)4173 int MYSQL_BIN_LOG::purge_logs_before_date(time_t purge_time)
4174 {
4175   int error;
4176   char to_log[FN_REFLEN];
4177   LOG_INFO log_info;
4178   MY_STAT stat_area;
4179   THD *thd= current_thd;
4180 
4181   DBUG_ENTER("purge_logs_before_date");
4182 
4183   mysql_mutex_lock(&LOCK_index);
4184   to_log[0]= 0;
4185 
4186   if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/)))
4187     goto err;
4188 
4189   while (strcmp(log_file_name, log_info.log_file_name) &&
4190 	 !is_active(log_info.log_file_name) &&
4191          !log_in_use(log_info.log_file_name))
4192   {
4193     if (!mysql_file_stat(m_key_file_log,
4194                          log_info.log_file_name, &stat_area, MYF(0)))
4195     {
4196       if (my_errno == ENOENT)
4197       {
4198         /*
4199           It's not fatal if we can't stat a log file that does not exist.
4200         */
4201         my_errno= 0;
4202       }
4203       else
4204       {
4205         /*
4206           Other than ENOENT are fatal
4207         */
4208         if (thd)
4209         {
4210           push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4211                               ER_BINLOG_PURGE_FATAL_ERR,
4212                               "a problem with getting info on being purged %s; "
4213                               "consider examining correspondence "
4214                               "of your binlog index file "
4215                               "to the actual binlog files",
4216                               log_info.log_file_name);
4217         }
4218         else
4219         {
4220           sql_print_information("Failed to delete log file '%s'",
4221                                 log_info.log_file_name);
4222         }
4223         error= LOG_INFO_FATAL;
4224         goto err;
4225       }
4226     }
4227     else
4228     {
4229       if (stat_area.st_mtime < purge_time)
4230         strmake(to_log,
4231                 log_info.log_file_name,
4232                 sizeof(log_info.log_file_name) - 1);
4233       else
4234         break;
4235     }
4236     if (find_next_log(&log_info, 0))
4237       break;
4238   }
4239 
4240   error= (to_log[0] ? purge_logs(to_log, 1, 0, 1, (ulonglong *) 0) : 0);
4241 
4242 err:
4243   mysql_mutex_unlock(&LOCK_index);
4244   DBUG_RETURN(error);
4245 }
4246 #endif /* HAVE_REPLICATION */
4247 
4248 
4249 /**
4250   Create a new log file name.
4251 
4252   @param buf		buf of at least FN_REFLEN where new name is stored
4253 
4254   @note
4255     If file name will be longer then FN_REFLEN it will be truncated
4256 */
4257 
make_log_name(char * buf,const char * log_ident)4258 void MYSQL_BIN_LOG::make_log_name(char* buf, const char* log_ident)
4259 {
4260   uint dir_len = dirname_length(log_file_name);
4261   if (dir_len >= FN_REFLEN)
4262     dir_len=FN_REFLEN-1;
4263   strnmov(buf, log_file_name, dir_len);
4264   strmake(buf+dir_len, log_ident, FN_REFLEN - dir_len -1);
4265 }
4266 
4267 
4268 /**
4269   Check if we are writing/reading to the given log file.
4270 */
4271 
is_active(const char * log_file_name_arg)4272 bool MYSQL_BIN_LOG::is_active(const char *log_file_name_arg)
4273 {
4274   return !strcmp(log_file_name, log_file_name_arg);
4275 }
4276 
4277 
4278 /*
4279   Wrappers around new_file_impl to avoid using argument
4280   to control locking. The argument 1) less readable 2) breaks
4281   incapsulation 3) allows external access to the class without
4282   a lock (which is not possible with private new_file_without_locking
4283   method).
4284 
4285   @retval
4286     nonzero - error
4287 */
4288 
new_file()4289 int MYSQL_BIN_LOG::new_file()
4290 {
4291   return new_file_impl(1);
4292 }
4293 
4294 /*
4295   @retval
4296     nonzero - error
4297  */
new_file_without_locking()4298 int MYSQL_BIN_LOG::new_file_without_locking()
4299 {
4300   return new_file_impl(0);
4301 }
4302 
4303 
4304 /**
4305   Start writing to a new log file or reopen the old file.
4306 
4307   @param need_lock		Set to 1 if caller has not locked LOCK_log
4308 
4309   @retval
4310     nonzero - error
4311 
4312   @note
4313     The new file name is stored last in the index file
4314 */
4315 
new_file_impl(bool need_lock)4316 int MYSQL_BIN_LOG::new_file_impl(bool need_lock)
4317 {
4318   int error= 0, close_on_error= FALSE;
4319   char new_name[FN_REFLEN], *new_name_ptr, *old_name, *file_to_open;
4320 
4321   DBUG_ENTER("MYSQL_BIN_LOG::new_file_impl");
4322   if (!is_open())
4323   {
4324     DBUG_PRINT("info",("log is closed"));
4325     DBUG_RETURN(error);
4326   }
4327 
4328   if (need_lock)
4329     mysql_mutex_lock(&LOCK_log);
4330   mysql_mutex_lock(&LOCK_index);
4331 
4332   mysql_mutex_assert_owner(&LOCK_log);
4333   mysql_mutex_assert_owner(&LOCK_index);
4334 
4335   /*
4336     if binlog is used as tc log, be sure all xids are "unlogged",
4337     so that on recover we only need to scan one - latest - binlog file
4338     for prepared xids. As this is expected to be a rare event,
4339     simple wait strategy is enough. We're locking LOCK_log to be sure no
4340     new Xid_log_event's are added to the log (and prepared_xids is not
4341     increased), and waiting on COND_prep_xids for late threads to
4342     catch up.
4343   */
4344   if (prepared_xids)
4345   {
4346     tc_log_page_waits++;
4347     mysql_mutex_lock(&LOCK_prep_xids);
4348     while (prepared_xids) {
4349       DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids));
4350       mysql_cond_wait(&COND_prep_xids, &LOCK_prep_xids);
4351     }
4352     mysql_mutex_unlock(&LOCK_prep_xids);
4353   }
4354 
4355   /* Reuse old name if not binlog and not update log */
4356   new_name_ptr= name;
4357 
4358   /*
4359     If user hasn't specified an extension, generate a new log name
4360     We have to do this here and not in open as we want to store the
4361     new file name in the current binary log file.
4362   */
4363   if ((error= generate_new_name(new_name, name)))
4364     goto end;
4365   new_name_ptr=new_name;
4366 
4367   if (log_type == LOG_BIN)
4368   {
4369     if (!no_auto_events)
4370     {
4371       /*
4372         We log the whole file name for log file as the user may decide
4373         to change base names at some point.
4374       */
4375       Rotate_log_event r(new_name+dirname_length(new_name),
4376                          0, LOG_EVENT_OFFSET, is_relay_log ? Rotate_log_event::RELAY_LOG : 0);
4377       if(DBUG_EVALUATE_IF("fault_injection_new_file_rotate_event", (error=close_on_error=TRUE), FALSE) ||
4378          (error= r.write(&log_file)))
4379       {
4380         DBUG_EXECUTE_IF("fault_injection_new_file_rotate_event", errno=2;);
4381         close_on_error= TRUE;
4382         my_printf_error(ER_ERROR_ON_WRITE, ER(ER_CANT_OPEN_FILE), MYF(ME_FATALERROR), name, errno);
4383         goto end;
4384       }
4385       bytes_written += r.data_written;
4386     }
4387     /*
4388       Update needs to be signalled even if there is no rotate event
4389       log rotation should give the waiting thread a signal to
4390       discover EOF and move on to the next log.
4391     */
4392     signal_update();
4393   }
4394   old_name=name;
4395   name=0;				// Don't free name
4396   close(LOG_CLOSE_TO_BE_OPENED | LOG_CLOSE_INDEX);
4397 
4398   /*
4399      Note that at this point, log_state != LOG_CLOSED (important for is_open()).
4400   */
4401 
4402   /*
4403      new_file() is only used for rotation (in FLUSH LOGS or because size >
4404      max_binlog_size or max_relay_log_size).
4405      If this is a binary log, the Format_description_log_event at the beginning of
4406      the new file should have created=0 (to distinguish with the
4407      Format_description_log_event written at server startup, which should
4408      trigger temp tables deletion on slaves.
4409   */
4410 
4411   /* reopen index binlog file, BUG#34582 */
4412   file_to_open= index_file_name;
4413   error= open_index_file(index_file_name, 0, FALSE);
4414   if (!error)
4415   {
4416     /* reopen the binary log file. */
4417     file_to_open= new_name_ptr;
4418     error= open(old_name, log_type, new_name_ptr, io_cache_type,
4419                 no_auto_events, max_size, 1, FALSE);
4420   }
4421 
4422   /* handle reopening errors */
4423   if (error)
4424   {
4425     my_printf_error(ER_CANT_OPEN_FILE, ER(ER_CANT_OPEN_FILE),
4426                     MYF(ME_FATALERROR), file_to_open, error);
4427     close_on_error= TRUE;
4428   }
4429 
4430   my_free(old_name);
4431 
4432 end:
4433 
4434   if (error && close_on_error /* rotate or reopen failed */)
4435   {
4436     /*
4437       Close whatever was left opened.
4438 
4439       We are keeping the behavior as it exists today, ie,
4440       we disable logging and move on (see: BUG#51014).
4441 
4442       TODO: as part of WL#1790 consider other approaches:
4443        - kill mysql (safety);
4444        - try multiple locations for opening a log file;
4445        - switch server to protected/readonly mode
4446        - ...
4447     */
4448     close(LOG_CLOSE_INDEX);
4449     sql_print_error("Could not open %s for logging (error %d). "
4450                      "Turning logging off for the whole duration "
4451                      "of the MySQL server process. To turn it on "
4452                      "again: fix the cause, shutdown the MySQL "
4453                      "server and restart it.",
4454                      new_name_ptr, errno);
4455   }
4456 
4457   if (need_lock)
4458     mysql_mutex_unlock(&LOCK_log);
4459   mysql_mutex_unlock(&LOCK_index);
4460 
4461   DBUG_RETURN(error);
4462 }
4463 
4464 
append(Log_event * ev)4465 bool MYSQL_BIN_LOG::append(Log_event* ev)
4466 {
4467   bool error = 0;
4468   mysql_mutex_lock(&LOCK_log);
4469   DBUG_ENTER("MYSQL_BIN_LOG::append");
4470 
4471   DBUG_ASSERT(log_file.type == SEQ_READ_APPEND);
4472   /*
4473     Log_event::write() is smart enough to use my_b_write() or
4474     my_b_append() depending on the kind of cache we have.
4475   */
4476   if (ev->write(&log_file))
4477   {
4478     error=1;
4479     goto err;
4480   }
4481   bytes_written+= ev->data_written;
4482   DBUG_PRINT("info",("max_size: %lu",max_size));
4483   if (flush_and_sync(0))
4484     goto err;
4485   if ((uint) my_b_append_tell(&log_file) > max_size)
4486     error= new_file_without_locking();
4487 err:
4488   mysql_mutex_unlock(&LOCK_log);
4489   signal_update();				// Safe as we don't call close
4490   DBUG_RETURN(error);
4491 }
4492 
4493 
appendv(const char * buf,uint len,...)4494 bool MYSQL_BIN_LOG::appendv(const char* buf, uint len,...)
4495 {
4496   bool error= 0;
4497   DBUG_ENTER("MYSQL_BIN_LOG::appendv");
4498   va_list(args);
4499   va_start(args,len);
4500 
4501   DBUG_ASSERT(log_file.type == SEQ_READ_APPEND);
4502 
4503   mysql_mutex_assert_owner(&LOCK_log);
4504   do
4505   {
4506     if (my_b_append(&log_file,(uchar*) buf,len))
4507     {
4508       error= 1;
4509       goto err;
4510     }
4511     bytes_written += len;
4512   } while ((buf=va_arg(args,const char*)) && (len=va_arg(args,uint)));
4513   DBUG_PRINT("info",("max_size: %lu",max_size));
4514   if (flush_and_sync(0))
4515     goto err;
4516   if ((uint) my_b_append_tell(&log_file) > max_size)
4517     error= new_file_without_locking();
4518 err:
4519   if (!error)
4520     signal_update();
4521   DBUG_RETURN(error);
4522 }
4523 
flush_and_sync(bool * synced)4524 bool MYSQL_BIN_LOG::flush_and_sync(bool *synced)
4525 {
4526   int err=0, fd=log_file.file;
4527   if (synced)
4528     *synced= 0;
4529   mysql_mutex_assert_owner(&LOCK_log);
4530   if (flush_io_cache(&log_file))
4531     return 1;
4532   uint sync_period= get_sync_period();
4533   if (sync_period && ++sync_counter >= sync_period)
4534   {
4535     sync_counter= 0;
4536     err= mysql_file_sync(fd, MYF(MY_WME));
4537     if (synced)
4538       *synced= 1;
4539   }
4540   return err;
4541 }
4542 
start_union_events(THD * thd,query_id_t query_id_param)4543 void MYSQL_BIN_LOG::start_union_events(THD *thd, query_id_t query_id_param)
4544 {
4545   DBUG_ASSERT(!thd->binlog_evt_union.do_union);
4546   thd->binlog_evt_union.do_union= TRUE;
4547   thd->binlog_evt_union.unioned_events= FALSE;
4548   thd->binlog_evt_union.unioned_events_trans= FALSE;
4549   thd->binlog_evt_union.first_query_id= query_id_param;
4550 }
4551 
stop_union_events(THD * thd)4552 void MYSQL_BIN_LOG::stop_union_events(THD *thd)
4553 {
4554   DBUG_ASSERT(thd->binlog_evt_union.do_union);
4555   thd->binlog_evt_union.do_union= FALSE;
4556 }
4557 
is_query_in_union(THD * thd,query_id_t query_id_param)4558 bool MYSQL_BIN_LOG::is_query_in_union(THD *thd, query_id_t query_id_param)
4559 {
4560   return (thd->binlog_evt_union.do_union &&
4561           query_id_param >= thd->binlog_evt_union.first_query_id);
4562 }
4563 
4564 /**
4565   This function checks if a transactional table was updated by the
4566   current transaction.
4567 
4568   @param thd The client thread that executed the current statement.
4569   @return
4570     @c true if a transactional table was updated, @c false otherwise.
4571 */
4572 bool
trans_has_updated_trans_table(const THD * thd)4573 trans_has_updated_trans_table(const THD* thd)
4574 {
4575   binlog_cache_mngr *const cache_mngr=
4576     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4577 
4578   return (cache_mngr ? !cache_mngr->trx_cache.empty() : 0);
4579 }
4580 
4581 /**
4582   This function checks if a transactional table was updated by the
4583   current statement.
4584 
4585   @param ha_list Registered storage engine handler list.
4586   @return
4587     @c true if a transactional table was updated, @c false otherwise.
4588 */
4589 bool
stmt_has_updated_trans_table(Ha_trx_info * ha_list)4590 stmt_has_updated_trans_table(Ha_trx_info* ha_list)
4591 {
4592   Ha_trx_info *ha_info;
4593   for (ha_info= ha_list; ha_info; ha_info= ha_info->next())
4594   {
4595     if (ha_info->is_trx_read_write() && ha_info->ht() != binlog_hton)
4596       return (TRUE);
4597   }
4598   return (FALSE);
4599 }
4600 
4601 /**
4602   This function checks if either a trx-cache or a non-trx-cache should
4603   be used. If @c bin_log_direct_non_trans_update is active or the format
4604   is either MIXED or ROW, the cache to be used depends on the flag @c
4605   is_transactional.
4606 
4607   On the other hand, if binlog_format is STMT or direct option is
4608   OFF, the trx-cache should be used if and only if the statement is
4609   transactional or the trx-cache is not empty. Otherwise, the
4610   non-trx-cache should be used.
4611 
4612   @param thd              The client thread.
4613   @param is_transactional The changes are related to a trx-table.
4614   @return
4615     @c true if a trx-cache should be used, @c false otherwise.
4616 */
use_trans_cache(const THD * thd,bool is_transactional)4617 bool use_trans_cache(const THD* thd, bool is_transactional)
4618 {
4619   binlog_cache_mngr *const cache_mngr=
4620     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4621 
4622   return
4623     ((thd->is_current_stmt_binlog_format_row() ||
4624      thd->variables.binlog_direct_non_trans_update) ? is_transactional :
4625      (is_transactional || !cache_mngr->trx_cache.empty()));
4626 }
4627 
4628 /**
4629   This function checks if a transaction, either a multi-statement
4630   or a single statement transaction is about to commit or not.
4631 
4632   @param thd The client thread that executed the current statement.
4633   @param all Committing a transaction (i.e. TRUE) or a statement
4634              (i.e. FALSE).
4635   @return
4636     @c true if committing a transaction, otherwise @c false.
4637 */
ending_trans(THD * thd,const bool all)4638 bool ending_trans(THD* thd, const bool all)
4639 {
4640   return (all || ending_single_stmt_trans(thd, all));
4641 }
4642 
4643 /**
4644   This function checks if a single statement transaction is about
4645   to commit or not.
4646 
4647   @param thd The client thread that executed the current statement.
4648   @param all Committing a transaction (i.e. TRUE) or a statement
4649              (i.e. FALSE).
4650   @return
4651     @c true if committing a single statement transaction, otherwise
4652     @c false.
4653 */
ending_single_stmt_trans(THD * thd,const bool all)4654 bool ending_single_stmt_trans(THD* thd, const bool all)
4655 {
4656   return (!all && !thd->in_multi_stmt_transaction_mode());
4657 }
4658 
4659 /**
4660   This function checks if a non-transactional table was updated by
4661   the current transaction.
4662 
4663   @param thd The client thread that executed the current statement.
4664   @return
4665     @c true if a non-transactional table was updated, @c false
4666     otherwise.
4667 */
trans_has_updated_non_trans_table(const THD * thd)4668 bool trans_has_updated_non_trans_table(const THD* thd)
4669 {
4670   return (thd->transaction.all.modified_non_trans_table ||
4671           thd->transaction.stmt.modified_non_trans_table);
4672 }
4673 
4674 /**
4675   This function checks if a non-transactional table was updated by the
4676   current statement.
4677 
4678   @param thd The client thread that executed the current statement.
4679   @return
4680     @c true if a non-transactional table was updated, @c false otherwise.
4681 */
stmt_has_updated_non_trans_table(const THD * thd)4682 bool stmt_has_updated_non_trans_table(const THD* thd)
4683 {
4684   return (thd->transaction.stmt.modified_non_trans_table);
4685 }
4686 
4687 /*
4688   These functions are placed in this file since they need access to
4689   binlog_hton, which has internal linkage.
4690 */
4691 
binlog_setup_trx_data()4692 int THD::binlog_setup_trx_data()
4693 {
4694   DBUG_ENTER("THD::binlog_setup_trx_data");
4695   binlog_cache_mngr *cache_mngr=
4696     (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4697 
4698   if (cache_mngr)
4699     DBUG_RETURN(0);                             // Already set up
4700 
4701   cache_mngr= (binlog_cache_mngr*) my_malloc(sizeof(binlog_cache_mngr), MYF(MY_ZEROFILL));
4702   if (!cache_mngr ||
4703       open_cached_file(&cache_mngr->stmt_cache.cache_log, mysql_tmpdir,
4704                        LOG_PREFIX, binlog_stmt_cache_size, MYF(MY_WME)) ||
4705       open_cached_file(&cache_mngr->trx_cache.cache_log, mysql_tmpdir,
4706                        LOG_PREFIX, binlog_cache_size, MYF(MY_WME)))
4707   {
4708     my_free(cache_mngr);
4709     DBUG_RETURN(1);                      // Didn't manage to set it up
4710   }
4711   thd_set_ha_data(this, binlog_hton, cache_mngr);
4712 
4713   cache_mngr= new (thd_get_ha_data(this, binlog_hton))
4714               binlog_cache_mngr(max_binlog_stmt_cache_size,
4715                                 max_binlog_cache_size,
4716                                 &binlog_stmt_cache_use,
4717                                 &binlog_stmt_cache_disk_use,
4718                                 &binlog_cache_use,
4719                                 &binlog_cache_disk_use);
4720   DBUG_RETURN(0);
4721 }
4722 
4723 /*
4724   Function to start a statement and optionally a transaction for the
4725   binary log.
4726 
4727   SYNOPSIS
4728     binlog_start_trans_and_stmt()
4729 
4730   DESCRIPTION
4731 
4732     This function does three things:
4733     - Start a transaction if not in autocommit mode or if a BEGIN
4734       statement has been seen.
4735 
4736     - Start a statement transaction to allow us to truncate the cache.
4737 
4738     - Save the currrent binlog position so that we can roll back the
4739       statement by truncating the cache.
4740 
4741       We only update the saved position if the old one was undefined,
4742       the reason is that there are some cases (e.g., for CREATE-SELECT)
4743       where the position is saved twice (e.g., both in
4744       select_create::prepare() and THD::binlog_write_table_map()) , but
4745       we should use the first. This means that calls to this function
4746       can be used to start the statement before the first table map
4747       event, to include some extra events.
4748  */
4749 
4750 void
binlog_start_trans_and_stmt()4751 THD::binlog_start_trans_and_stmt()
4752 {
4753   binlog_cache_mngr *cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4754   DBUG_ENTER("binlog_start_trans_and_stmt");
4755   DBUG_PRINT("enter", ("cache_mngr: %p  cache_mngr->trx_cache.get_prev_position(): %lu",
4756                        cache_mngr,
4757                        (cache_mngr ? (ulong) cache_mngr->trx_cache.get_prev_position() :
4758                         (ulong) 0)));
4759 
4760   if (cache_mngr == NULL ||
4761       cache_mngr->trx_cache.get_prev_position() == MY_OFF_T_UNDEF)
4762   {
4763     this->binlog_set_stmt_begin();
4764     if (in_multi_stmt_transaction_mode())
4765       trans_register_ha(this, TRUE, binlog_hton);
4766     trans_register_ha(this, FALSE, binlog_hton);
4767     /*
4768       Mark statement transaction as read/write. We never start
4769       a binary log transaction and keep it read-only,
4770       therefore it's best to mark the transaction read/write just
4771       at the same time we start it.
4772       Not necessary to mark the normal transaction read/write
4773       since the statement-level flag will be propagated automatically
4774       inside ha_commit_trans.
4775     */
4776     ha_data[binlog_hton->slot].ha_info[0].set_trx_read_write();
4777   }
4778   DBUG_VOID_RETURN;
4779 }
4780 
binlog_set_stmt_begin()4781 void THD::binlog_set_stmt_begin() {
4782   binlog_cache_mngr *cache_mngr=
4783     (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4784 
4785   /*
4786     The call to binlog_trans_log_savepos() might create the cache_mngr
4787     structure, if it didn't exist before, so we save the position
4788     into an auto variable and then write it into the transaction
4789     data for the binary log (i.e., cache_mngr).
4790   */
4791   my_off_t pos= 0;
4792   binlog_trans_log_savepos(this, &pos);
4793   cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4794   cache_mngr->trx_cache.set_prev_position(pos);
4795 }
4796 
4797 
4798 /**
4799   This function writes a table map to the binary log.
4800   Note that in order to keep the signature uniform with related methods,
4801   we use a redundant parameter to indicate whether a transactional table
4802   was changed or not.
4803 
4804   @param table             a pointer to the table.
4805   @param is_transactional  @c true indicates a transactional table,
4806                            otherwise @c false a non-transactional.
4807   @return
4808     nonzero if an error pops up when writing the table map event.
4809 */
binlog_write_table_map(TABLE * table,bool is_transactional)4810 int THD::binlog_write_table_map(TABLE *table, bool is_transactional)
4811 {
4812   int error;
4813   DBUG_ENTER("THD::binlog_write_table_map");
4814   DBUG_PRINT("enter", ("table: 0x%lx  (%s: #%lu)",
4815                        (long) table, table->s->table_name.str,
4816                        table->s->table_map_id));
4817 
4818   /* Pre-conditions */
4819   DBUG_ASSERT(is_current_stmt_binlog_format_row() && mysql_bin_log.is_open());
4820   DBUG_ASSERT(table->s->table_map_id != ULONG_MAX);
4821 
4822   Table_map_log_event
4823     the_event(this, table, table->s->table_map_id, is_transactional);
4824 
4825   if (binlog_table_maps == 0)
4826     binlog_start_trans_and_stmt();
4827 
4828   binlog_cache_mngr *const cache_mngr=
4829     (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4830 
4831   IO_CACHE *file=
4832     cache_mngr->get_binlog_cache_log(use_trans_cache(this, is_transactional));
4833   if ((error= the_event.write(file)))
4834     DBUG_RETURN(error);
4835 
4836   binlog_table_maps++;
4837   DBUG_RETURN(0);
4838 }
4839 
4840 /**
4841   This function retrieves a pending row event from a cache which is
4842   specified through the parameter @c is_transactional. Respectively, when it
4843   is @c true, the pending event is returned from the transactional cache.
4844   Otherwise from the non-transactional cache.
4845 
4846   @param is_transactional  @c true indicates a transactional cache,
4847                            otherwise @c false a non-transactional.
4848   @return
4849     The row event if any.
4850 */
4851 Rows_log_event*
binlog_get_pending_rows_event(bool is_transactional) const4852 THD::binlog_get_pending_rows_event(bool is_transactional) const
4853 {
4854   Rows_log_event* rows= NULL;
4855   binlog_cache_mngr *const cache_mngr=
4856     (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4857 
4858   /*
4859     This is less than ideal, but here's the story: If there is no cache_mngr,
4860     prepare_pending_rows_event() has never been called (since the cache_mngr
4861     is set up there). In that case, we just return NULL.
4862    */
4863   if (cache_mngr)
4864   {
4865     binlog_cache_data *cache_data=
4866       cache_mngr->get_binlog_cache_data(use_trans_cache(this, is_transactional));
4867 
4868     rows= cache_data->pending();
4869   }
4870   return (rows);
4871 }
4872 
4873 /**
4874   This function stores a pending row event into a cache which is specified
4875   through the parameter @c is_transactional. Respectively, when it is @c
4876   true, the pending event is stored into the transactional cache. Otherwise
4877   into the non-transactional cache.
4878 
4879   @param evt               a pointer to the row event.
4880   @param is_transactional  @c true indicates a transactional cache,
4881                            otherwise @c false a non-transactional.
4882 */
4883 void
binlog_set_pending_rows_event(Rows_log_event * ev,bool is_transactional)4884 THD::binlog_set_pending_rows_event(Rows_log_event* ev, bool is_transactional)
4885 {
4886   if (thd_get_ha_data(this, binlog_hton) == NULL)
4887     binlog_setup_trx_data();
4888 
4889   binlog_cache_mngr *const cache_mngr=
4890     (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4891 
4892   DBUG_ASSERT(cache_mngr);
4893 
4894   binlog_cache_data *cache_data=
4895     cache_mngr->get_binlog_cache_data(use_trans_cache(this, is_transactional));
4896 
4897   cache_data->set_pending(ev);
4898 }
4899 
4900 
4901 /**
4902   This function removes the pending rows event, discarding any outstanding
4903   rows. If there is no pending rows event available, this is effectively a
4904   no-op.
4905 
4906   @param thd               a pointer to the user thread.
4907   @param is_transactional  @c true indicates a transactional cache,
4908                            otherwise @c false a non-transactional.
4909 */
4910 int
remove_pending_rows_event(THD * thd,bool is_transactional)4911 MYSQL_BIN_LOG::remove_pending_rows_event(THD *thd, bool is_transactional)
4912 {
4913   DBUG_ENTER("MYSQL_BIN_LOG::remove_pending_rows_event");
4914 
4915   binlog_cache_mngr *const cache_mngr=
4916     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4917 
4918   DBUG_ASSERT(cache_mngr);
4919 
4920   binlog_cache_data *cache_data=
4921     cache_mngr->get_binlog_cache_data(use_trans_cache(thd, is_transactional));
4922 
4923   if (Rows_log_event* pending= cache_data->pending())
4924   {
4925     delete pending;
4926     cache_data->set_pending(NULL);
4927   }
4928 
4929   DBUG_RETURN(0);
4930 }
4931 
4932 /*
4933   Moves the last bunch of rows from the pending Rows event to a cache (either
4934   transactional cache if is_transaction is @c true, or the non-transactional
4935   cache otherwise. Sets a new pending event.
4936 
4937   @param thd               a pointer to the user thread.
4938   @param evt               a pointer to the row event.
4939   @param is_transactional  @c true indicates a transactional cache,
4940                            otherwise @c false a non-transactional.
4941 */
4942 int
flush_and_set_pending_rows_event(THD * thd,Rows_log_event * event,bool is_transactional)4943 MYSQL_BIN_LOG::flush_and_set_pending_rows_event(THD *thd,
4944                                                 Rows_log_event* event,
4945                                                 bool is_transactional)
4946 {
4947   DBUG_ENTER("MYSQL_BIN_LOG::flush_and_set_pending_rows_event(event)");
4948   DBUG_ASSERT(mysql_bin_log.is_open());
4949   DBUG_PRINT("enter", ("event: 0x%lx", (long) event));
4950 
4951   int error= 0;
4952   binlog_cache_mngr *const cache_mngr=
4953     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4954 
4955   DBUG_ASSERT(cache_mngr);
4956 
4957   binlog_cache_data *cache_data=
4958     cache_mngr->get_binlog_cache_data(use_trans_cache(thd, is_transactional));
4959 
4960   DBUG_PRINT("info", ("cache_mngr->pending(): 0x%lx", (long) cache_data->pending()));
4961 
4962   if (Rows_log_event* pending= cache_data->pending())
4963   {
4964     IO_CACHE *file= &cache_data->cache_log;
4965 
4966     /*
4967       Write pending event to the cache.
4968     */
4969     DBUG_EXECUTE_IF("simulate_disk_full_at_flush_pending",
4970                     {DBUG_SET("+d,simulate_file_write_error");});
4971     if (pending->write(file))
4972     {
4973       set_write_error(thd, is_transactional);
4974       if (check_write_error(thd) && cache_data &&
4975           stmt_has_updated_non_trans_table(thd))
4976         cache_data->set_incident();
4977       delete pending;
4978       cache_data->set_pending(NULL);
4979       DBUG_EXECUTE_IF("simulate_disk_full_at_flush_pending",
4980                       {DBUG_SET("-d,simulate_file_write_error");});
4981       DBUG_RETURN(1);
4982     }
4983 
4984     delete pending;
4985   }
4986 
4987   thd->binlog_set_pending_rows_event(event, is_transactional);
4988 
4989   DBUG_RETURN(error);
4990 }
4991 
4992 /**
4993   Write an event to the binary log.
4994 */
4995 
write(Log_event * event_info)4996 bool MYSQL_BIN_LOG::write(Log_event *event_info)
4997 {
4998   THD *thd= event_info->thd;
4999   bool error= 1;
5000   DBUG_ENTER("MYSQL_BIN_LOG::write(Log_event *)");
5001   binlog_cache_data *cache_data= 0;
5002   bool is_trans_cache= FALSE;
5003 
5004   if (thd->binlog_evt_union.do_union)
5005   {
5006     /*
5007       In Stored function; Remember that function call caused an update.
5008       We will log the function call to the binary log on function exit
5009     */
5010     thd->binlog_evt_union.unioned_events= TRUE;
5011     thd->binlog_evt_union.unioned_events_trans |=
5012       event_info->use_trans_cache();
5013     DBUG_RETURN(0);
5014   }
5015 
5016   /*
5017     We only end the statement if we are in a top-level statement.  If
5018     we are inside a stored function, we do not end the statement since
5019     this will close all tables on the slave.
5020   */
5021   bool const end_stmt=
5022     thd->locked_tables_mode && thd->lex->requires_prelocking();
5023   if (thd->binlog_flush_pending_rows_event(end_stmt,
5024                                            event_info->use_trans_cache()))
5025     DBUG_RETURN(error);
5026 
5027   /*
5028      In most cases this is only called if 'is_open()' is true; in fact this is
5029      mostly called if is_open() *was* true a few instructions before, but it
5030      could have changed since.
5031   */
5032   if (likely(is_open()))
5033   {
5034 #ifdef HAVE_REPLICATION
5035     /*
5036       In the future we need to add to the following if tests like
5037       "do the involved tables match (to be implemented)
5038       binlog_[wild_]{do|ignore}_table?" (WL#1049)"
5039     */
5040     const char *local_db= event_info->get_db();
5041     if ((thd && !(thd->variables.option_bits & OPTION_BIN_LOG)) ||
5042 	(thd->lex->sql_command != SQLCOM_ROLLBACK_TO_SAVEPOINT &&
5043          thd->lex->sql_command != SQLCOM_SAVEPOINT &&
5044          !binlog_filter->db_ok(local_db)))
5045       DBUG_RETURN(0);
5046 #endif /* HAVE_REPLICATION */
5047 
5048     IO_CACHE *file= NULL;
5049 
5050     if (event_info->use_direct_logging())
5051     {
5052       file= &log_file;
5053       mysql_mutex_lock(&LOCK_log);
5054     }
5055     else
5056     {
5057       if (thd->binlog_setup_trx_data())
5058         goto err;
5059 
5060       binlog_cache_mngr *const cache_mngr=
5061         (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
5062 
5063       is_trans_cache= use_trans_cache(thd, event_info->use_trans_cache());
5064       file= cache_mngr->get_binlog_cache_log(is_trans_cache);
5065       cache_data= cache_mngr->get_binlog_cache_data(is_trans_cache);
5066 
5067       if (thd->lex->stmt_accessed_non_trans_temp_table())
5068         cache_data->set_changes_to_non_trans_temp_table();
5069 
5070       thd->binlog_start_trans_and_stmt();
5071     }
5072     DBUG_PRINT("info",("event type: %d",event_info->get_type_code()));
5073 
5074     /*
5075        No check for auto events flag here - this write method should
5076        never be called if auto-events are enabled.
5077 
5078        Write first log events which describe the 'run environment'
5079        of the SQL command. If row-based binlogging, Insert_id, Rand
5080        and other kind of "setting context" events are not needed.
5081     */
5082     if (thd)
5083     {
5084       if (!thd->is_current_stmt_binlog_format_row())
5085       {
5086         if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
5087         {
5088           Intvar_log_event e(thd,(uchar) LAST_INSERT_ID_EVENT,
5089                              thd->first_successful_insert_id_in_prev_stmt_for_binlog);
5090           if (e.write(file))
5091             goto err;
5092         }
5093         if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
5094         {
5095           DBUG_PRINT("info",("number of auto_inc intervals: %u",
5096                              thd->auto_inc_intervals_in_cur_stmt_for_binlog.
5097                              nb_elements()));
5098           Intvar_log_event e(thd, (uchar) INSERT_ID_EVENT,
5099                              thd->auto_inc_intervals_in_cur_stmt_for_binlog.
5100                              minimum());
5101           if (e.write(file))
5102             goto err;
5103         }
5104         if (thd->rand_used)
5105         {
5106           Rand_log_event e(thd,thd->rand_saved_seed1,thd->rand_saved_seed2);
5107           if (e.write(file))
5108             goto err;
5109         }
5110         if (thd->user_var_events.elements)
5111         {
5112           for (uint i= 0; i < thd->user_var_events.elements; i++)
5113           {
5114             BINLOG_USER_VAR_EVENT *user_var_event;
5115             get_dynamic(&thd->user_var_events,(uchar*) &user_var_event, i);
5116 
5117             /* setting flags for user var log event */
5118             uchar flags= User_var_log_event::UNDEF_F;
5119             if (user_var_event->unsigned_flag)
5120               flags|= User_var_log_event::UNSIGNED_F;
5121 
5122             User_var_log_event e(thd, user_var_event->user_var_event->name.str,
5123                                  user_var_event->user_var_event->name.length,
5124                                  user_var_event->value,
5125                                  user_var_event->length,
5126                                  user_var_event->type,
5127                                  user_var_event->charset_number,
5128                                  flags);
5129             if (e.write(file))
5130               goto err;
5131           }
5132         }
5133       }
5134     }
5135 
5136     /*
5137       Write the event.
5138     */
5139     if (event_info->write(file) ||
5140         DBUG_EVALUATE_IF("injecting_fault_writing", 1, 0))
5141       goto err;
5142 
5143     error= 0;
5144 err:
5145     if (event_info->use_direct_logging())
5146     {
5147       if (!error)
5148       {
5149         bool synced;
5150         if ((error= flush_and_sync(&synced)))
5151         {
5152           mysql_mutex_unlock(&LOCK_log);
5153         }
5154         else if ((error= RUN_HOOK(binlog_storage, after_flush,
5155                  (thd, log_file_name, file->pos_in_file, synced))))
5156         {
5157           sql_print_error("Failed to run 'after_flush' hooks");
5158           mysql_mutex_unlock(&LOCK_log);
5159         }
5160         else
5161         {
5162           bool check_purge;
5163           signal_update();
5164           error= rotate(false, &check_purge);
5165           mysql_mutex_unlock(&LOCK_log);
5166           if (!error && check_purge)
5167             purge();
5168         }
5169       }
5170       else
5171       {
5172         mysql_mutex_unlock(&LOCK_log);
5173       }
5174     }
5175 
5176     if (error)
5177     {
5178       set_write_error(thd, is_trans_cache);
5179       if (check_write_error(thd) && cache_data &&
5180           stmt_has_updated_non_trans_table(thd))
5181         cache_data->set_incident();
5182     }
5183   }
5184 
5185   DBUG_RETURN(error);
5186 }
5187 
5188 
error_log_print(enum loglevel level,const char * format,va_list args)5189 int error_log_print(enum loglevel level, const char *format,
5190                     va_list args)
5191 {
5192   return logger.error_log_print(level, format, args);
5193 }
5194 
5195 
slow_log_print(THD * thd,const char * query,uint query_length,ulonglong current_utime)5196 bool slow_log_print(THD *thd, const char *query, uint query_length,
5197                     ulonglong current_utime)
5198 {
5199   return logger.slow_log_print(thd, query, query_length, current_utime);
5200 }
5201 
5202 
log_command(THD * thd,enum enum_server_command command)5203 bool LOGGER::log_command(THD *thd, enum enum_server_command command)
5204 {
5205 #ifndef NO_EMBEDDED_ACCESS_CHECKS
5206   Security_context *sctx= thd->security_ctx;
5207 #endif
5208   /*
5209     Log command if we have at least one log event handler enabled and want
5210     to log this king of commands
5211   */
5212   if (*general_log_handler_list && (what_to_log & (1L << (uint) command)))
5213   {
5214     if ((thd->variables.option_bits & OPTION_LOG_OFF)
5215 #ifndef NO_EMBEDDED_ACCESS_CHECKS
5216          && (sctx->master_access & SUPER_ACL)
5217 #endif
5218        )
5219     {
5220       /* No logging */
5221       return FALSE;
5222     }
5223 
5224     return TRUE;
5225   }
5226 
5227   return FALSE;
5228 }
5229 
5230 
general_log_print(THD * thd,enum enum_server_command command,const char * format,...)5231 bool general_log_print(THD *thd, enum enum_server_command command,
5232                        const char *format, ...)
5233 {
5234   va_list args;
5235   uint error= 0;
5236 
5237   /* Print the message to the buffer if we want to log this king of commands */
5238   if (! logger.log_command(thd, command))
5239     return FALSE;
5240 
5241   va_start(args, format);
5242   error= logger.general_log_print(thd, command, format, args);
5243   va_end(args);
5244 
5245   return error;
5246 }
5247 
general_log_write(THD * thd,enum enum_server_command command,const char * query,uint query_length)5248 bool general_log_write(THD *thd, enum enum_server_command command,
5249                        const char *query, uint query_length)
5250 {
5251   /* Write the message to the log if we want to log this king of commands */
5252   if (logger.log_command(thd, command))
5253     return logger.general_log_write(thd, command, query, query_length);
5254 
5255   return FALSE;
5256 }
5257 
5258 /**
5259   The method executes rotation when LOCK_log is already acquired
5260   by the caller.
5261 
5262   @param force_rotate  caller can request the log rotation
5263   @param check_purge   is set to true if rotation took place
5264 
5265   @note
5266     If rotation fails, for instance the server was unable
5267     to create a new log file, we still try to write an
5268     incident event to the current log.
5269 
5270   @retval
5271     nonzero - error in rotating routine.
5272 */
rotate(bool force_rotate,bool * check_purge)5273 int MYSQL_BIN_LOG::rotate(bool force_rotate, bool* check_purge)
5274 {
5275   int error= 0;
5276   DBUG_ENTER("MYSQL_BIN_LOG::rotate");
5277 
5278   //todo: fix the macro def and restore safe_mutex_assert_owner(&LOCK_log);
5279   *check_purge= false;
5280 
5281   if (force_rotate || (my_b_tell(&log_file) >= (my_off_t) max_size))
5282   {
5283     if ((error= new_file_without_locking()))
5284       /**
5285          Be conservative... There are possible lost events (eg,
5286          failing to log the Execute_load_query_log_event
5287          on a LOAD DATA while using a non-transactional
5288          table)!
5289 
5290          We give it a shot and try to write an incident event anyway
5291          to the current log.
5292       */
5293       if (!write_incident(current_thd, FALSE))
5294         flush_and_sync(0);
5295 
5296     *check_purge= true;
5297   }
5298   DBUG_RETURN(error);
5299 }
5300 
5301 /**
5302   The method executes logs purging routine.
5303 
5304   @retval
5305     nonzero - error in rotating routine.
5306 */
purge()5307 void MYSQL_BIN_LOG::purge()
5308 {
5309 #ifdef HAVE_REPLICATION
5310   if (expire_logs_days)
5311   {
5312     DEBUG_SYNC(current_thd, "at_purge_logs_before_date");
5313     time_t purge_time= my_time(0) - expire_logs_days*24*60*60;
5314     if (purge_time >= 0)
5315     {
5316       purge_logs_before_date(purge_time);
5317     }
5318   }
5319 #endif
5320 }
5321 
5322 /**
5323   The method is a shortcut of @c rotate() and @c purge().
5324   LOCK_log is acquired prior to rotate and is released after it.
5325 
5326   @param force_rotate  caller can request the log rotation
5327 
5328   @retval
5329     nonzero - error in rotating routine.
5330 */
rotate_and_purge(bool force_rotate)5331 int MYSQL_BIN_LOG::rotate_and_purge(bool force_rotate)
5332 {
5333   int error= 0;
5334   DBUG_ENTER("MYSQL_BIN_LOG::rotate_and_purge");
5335   bool check_purge= false;
5336 
5337   //todo: fix the macro def and restore safe_mutex_assert_not_owner(&LOCK_log);
5338   mysql_mutex_lock(&LOCK_log);
5339   error= rotate(force_rotate, &check_purge);
5340   /*
5341     NOTE: Run purge_logs wo/ holding LOCK_log because it does not need
5342           the mutex. Otherwise causes various deadlocks.
5343   */
5344   mysql_mutex_unlock(&LOCK_log);
5345 
5346   if (!error && check_purge)
5347     purge();
5348 
5349   DBUG_RETURN(error);
5350 }
5351 
next_file_id()5352 uint MYSQL_BIN_LOG::next_file_id()
5353 {
5354   uint res;
5355   mysql_mutex_lock(&LOCK_log);
5356   res = file_id++;
5357   mysql_mutex_unlock(&LOCK_log);
5358   return res;
5359 }
5360 
5361 
5362 /*
5363   Write the contents of a cache to the binary log.
5364 
5365   SYNOPSIS
5366     write_cache()
5367     cache    Cache to write to the binary log
5368     lock_log True if the LOCK_log mutex should be aquired, false otherwise
5369     sync_log True if the log should be flushed and synced
5370 
5371   DESCRIPTION
5372     Write the contents of the cache to the binary log. The cache will
5373     be reset as a READ_CACHE to be able to read the contents from it.
5374  */
5375 
write_cache(IO_CACHE * cache,bool lock_log,bool sync_log)5376 int MYSQL_BIN_LOG::write_cache(IO_CACHE *cache, bool lock_log, bool sync_log)
5377 {
5378   Mutex_sentry sentry(lock_log ? &LOCK_log : NULL);
5379 
5380   if (reinit_io_cache(cache, READ_CACHE, 0, 0, 0))
5381     return ER_ERROR_ON_WRITE;
5382   uint length= my_b_bytes_in_cache(cache), group, carry, hdr_offs;
5383   long val;
5384   uchar header[LOG_EVENT_HEADER_LEN];
5385 
5386   /*
5387     The events in the buffer have incorrect end_log_pos data
5388     (relative to beginning of group rather than absolute),
5389     so we'll recalculate them in situ so the binlog is always
5390     correct, even in the middle of a group. This is possible
5391     because we now know the start position of the group (the
5392     offset of this cache in the log, if you will); all we need
5393     to do is to find all event-headers, and add the position of
5394     the group to the end_log_pos of each event.  This is pretty
5395     straight forward, except that we read the cache in segments,
5396     so an event-header might end up on the cache-border and get
5397     split.
5398   */
5399 
5400   group= (uint)my_b_tell(&log_file);
5401   hdr_offs= carry= 0;
5402 
5403   do
5404   {
5405     /*
5406       if we only got a partial header in the last iteration,
5407       get the other half now and process a full header.
5408     */
5409     if (unlikely(carry > 0))
5410     {
5411       DBUG_ASSERT(carry < LOG_EVENT_HEADER_LEN);
5412 
5413       /* assemble both halves */
5414       memcpy(&header[carry], (char *)cache->read_pos, LOG_EVENT_HEADER_LEN - carry);
5415 
5416       /* fix end_log_pos */
5417       val= uint4korr(&header[LOG_POS_OFFSET]) + group;
5418       int4store(&header[LOG_POS_OFFSET], val);
5419 
5420       /* write the first half of the split header */
5421       if (my_b_write(&log_file, header, carry))
5422         return ER_ERROR_ON_WRITE;
5423 
5424       /*
5425         copy fixed second half of header to cache so the correct
5426         version will be written later.
5427       */
5428       memcpy((char *)cache->read_pos, &header[carry], LOG_EVENT_HEADER_LEN - carry);
5429 
5430       /* next event header at ... */
5431       hdr_offs = uint4korr(&header[EVENT_LEN_OFFSET]) - carry;
5432 
5433       carry= 0;
5434     }
5435 
5436     /* if there is anything to write, process it. */
5437 
5438     if (likely(length > 0))
5439     {
5440       /*
5441         process all event-headers in this (partial) cache.
5442         if next header is beyond current read-buffer,
5443         we'll get it later (though not necessarily in the
5444         very next iteration, just "eventually").
5445       */
5446 
5447       while (hdr_offs < length)
5448       {
5449         /*
5450           partial header only? save what we can get, process once
5451           we get the rest.
5452         */
5453 
5454         if (hdr_offs + LOG_EVENT_HEADER_LEN > length)
5455         {
5456           carry= length - hdr_offs;
5457           memcpy(header, (char *)cache->read_pos + hdr_offs, carry);
5458           length= hdr_offs;
5459         }
5460         else
5461         {
5462           /* we've got a full event-header, and it came in one piece */
5463 
5464           uchar *log_pos= (uchar *)cache->read_pos + hdr_offs + LOG_POS_OFFSET;
5465 
5466           /* fix end_log_pos */
5467           val= uint4korr(log_pos) + group;
5468           int4store(log_pos, val);
5469 
5470           /* next event header at ... */
5471           log_pos= (uchar *)cache->read_pos + hdr_offs + EVENT_LEN_OFFSET;
5472           hdr_offs += uint4korr(log_pos);
5473 
5474         }
5475       }
5476 
5477       /*
5478         Adjust hdr_offs. Note that it may still point beyond the segment
5479         read in the next iteration; if the current event is very long,
5480         it may take a couple of read-iterations (and subsequent adjustments
5481         of hdr_offs) for it to point into the then-current segment.
5482         If we have a split header (!carry), hdr_offs will be set at the
5483         beginning of the next iteration, overwriting the value we set here:
5484       */
5485       hdr_offs -= length;
5486     }
5487 
5488     /* Write data to the binary log file */
5489     if (my_b_write(&log_file, cache->read_pos, length))
5490       return ER_ERROR_ON_WRITE;
5491     cache->read_pos=cache->read_end;		// Mark buffer used up
5492   } while ((length= my_b_fill(cache)));
5493 
5494   DBUG_ASSERT(carry == 0);
5495 
5496   if (sync_log)
5497     return flush_and_sync(0);
5498 
5499   return 0;                                     // All OK
5500 }
5501 
5502 /*
5503   Helper function to get the error code of the query to be binlogged.
5504  */
query_error_code(THD * thd,bool not_killed)5505 int query_error_code(THD *thd, bool not_killed)
5506 {
5507   int error;
5508 
5509   if (not_killed || (thd->killed == THD::KILL_BAD_DATA))
5510   {
5511     error= thd->is_error() ? thd->stmt_da->sql_errno() : 0;
5512 
5513     /* thd->stmt_da->sql_errno() might be ER_SERVER_SHUTDOWN or
5514        ER_QUERY_INTERRUPTED, So here we need to make sure that error
5515        is not set to these errors when specified not_killed by the
5516        caller.
5517     */
5518     if (error == ER_SERVER_SHUTDOWN || error == ER_QUERY_INTERRUPTED)
5519       error= 0;
5520   }
5521   else
5522   {
5523     /* killed status for DELAYED INSERT thread should never be used */
5524     DBUG_ASSERT(!(thd->system_thread & SYSTEM_THREAD_DELAYED_INSERT));
5525     error= thd->killed_errno();
5526   }
5527 
5528   return error;
5529 }
5530 
write_incident(THD * thd,bool lock)5531 bool MYSQL_BIN_LOG::write_incident(THD *thd, bool lock)
5532 {
5533   uint error= 0;
5534   DBUG_ENTER("MYSQL_BIN_LOG::write_incident");
5535 
5536   if (!is_open())
5537     DBUG_RETURN(error);
5538 
5539   LEX_STRING const write_error_msg=
5540     { C_STRING_WITH_LEN("error writing to the binary log") };
5541   Incident incident= INCIDENT_LOST_EVENTS;
5542   Incident_log_event ev(thd, incident, write_error_msg);
5543   if (lock)
5544     mysql_mutex_lock(&LOCK_log);
5545   error= ev.write(&log_file);
5546   if (lock)
5547   {
5548     if (!error && !(error= flush_and_sync(0)))
5549     {
5550       bool check_purge= false;
5551       signal_update();
5552       error= rotate(false, &check_purge);
5553       mysql_mutex_unlock(&LOCK_log);
5554       if (!error && check_purge)
5555         purge();
5556     }
5557     else
5558     {
5559       mysql_mutex_unlock(&LOCK_log);
5560     }
5561   }
5562   DBUG_RETURN(error);
5563 }
5564 
5565 /**
5566   Write a cached log entry to the binary log.
5567   - To support transaction over replication, we wrap the transaction
5568   with BEGIN/COMMIT or BEGIN/ROLLBACK in the binary log.
5569   We want to write a BEGIN/ROLLBACK block when a non-transactional table
5570   was updated in a transaction which was rolled back. This is to ensure
5571   that the same updates are run on the slave.
5572 
5573   @param thd
5574   @param cache		The cache to copy to the binlog
5575   @param commit_event   The commit event to print after writing the
5576                         contents of the cache.
5577   @param incident       Defines if an incident event should be created to
5578                         notify that some non-transactional changes did
5579                         not get into the binlog.
5580 
5581   @note
5582     We only come here if there is something in the cache.
5583   @note
5584     The thing in the cache is always a complete transaction.
5585   @note
5586     'cache' needs to be reinitialized after this functions returns.
5587 */
5588 
write(THD * thd,IO_CACHE * cache,Log_event * commit_event,bool incident)5589 bool MYSQL_BIN_LOG::write(THD *thd, IO_CACHE *cache, Log_event *commit_event,
5590                           bool incident)
5591 {
5592   DBUG_ENTER("MYSQL_BIN_LOG::write(THD *, IO_CACHE *, Log_event *)");
5593 
5594   DBUG_ASSERT(is_open());
5595   if (likely(is_open()))                       // Should always be true
5596   {
5597     bool check_purge;
5598 
5599     mysql_mutex_lock(&LOCK_log);
5600     /*
5601       We only bother to write to the binary log if there is anything
5602       to write.
5603      */
5604     if (my_b_tell(cache) > 0)
5605     {
5606       /*
5607         Log "BEGIN" at the beginning of every transaction.  Here, a
5608         transaction is either a BEGIN..COMMIT block or a single
5609         statement in autocommit mode.
5610       */
5611       Query_log_event qinfo(thd, STRING_WITH_LEN("BEGIN"), TRUE, FALSE, TRUE, 0);
5612       if (qinfo.write(&log_file))
5613         goto err;
5614       DBUG_EXECUTE_IF("crash_before_writing_xid",
5615                       {
5616                         if ((write_error= write_cache(cache, false, true)))
5617                           DBUG_PRINT("info", ("error writing binlog cache: %d",
5618                                                write_error));
5619                         DBUG_PRINT("info", ("crashing before writing xid"));
5620                         DBUG_SUICIDE();
5621                       });
5622 
5623       if ((write_error= write_cache(cache, false, false)))
5624         goto err;
5625 
5626       if (commit_event && commit_event->write(&log_file))
5627         goto err;
5628 
5629       if (incident && write_incident(thd, FALSE))
5630         goto err;
5631 
5632       bool synced= 0;
5633       if (flush_and_sync(&synced))
5634         goto err;
5635       DBUG_EXECUTE_IF("half_binlogged_transaction", DBUG_SUICIDE(););
5636       if (cache->error)				// Error on read
5637       {
5638         sql_print_error(ER(ER_ERROR_ON_READ), cache->file_name, errno);
5639         write_error=1;				// Don't give more errors
5640         goto err;
5641       }
5642 
5643       if (RUN_HOOK(binlog_storage, after_flush,
5644                    (thd, log_file_name, log_file.pos_in_file, synced)))
5645       {
5646         sql_print_error("Failed to run 'after_flush' hooks");
5647         write_error=1;
5648         goto err;
5649       }
5650 
5651       signal_update();
5652     }
5653 
5654     /*
5655       if commit_event is Xid_log_event, increase the number of
5656       prepared_xids (it's decreasd in ::unlog()). Binlog cannot be rotated
5657       if there're prepared xids in it - see the comment in new_file() for
5658       an explanation.
5659       If the commit_event is not Xid_log_event (then it's a Query_log_event)
5660       rotate binlog, if necessary.
5661     */
5662     if (commit_event && commit_event->get_type_code() == XID_EVENT)
5663     {
5664       mysql_mutex_lock(&LOCK_prep_xids);
5665       prepared_xids++;
5666       mysql_mutex_unlock(&LOCK_prep_xids);
5667       mysql_mutex_unlock(&LOCK_log);
5668     }
5669     else
5670     {
5671       if (rotate(false, &check_purge))
5672         goto err;
5673       mysql_mutex_unlock(&LOCK_log);
5674       if (check_purge)
5675         purge();
5676     }
5677   }
5678 
5679   DBUG_RETURN(0);
5680 
5681 err:
5682   if (!write_error)
5683   {
5684     write_error= 1;
5685     sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
5686   }
5687   mysql_mutex_unlock(&LOCK_log);
5688   DBUG_RETURN(1);
5689 }
5690 
5691 
5692 /**
5693   Wait until we get a signal that the relay log has been updated.
5694 
5695   @param thd		Thread variable
5696 
5697   @note
5698     One must have a lock on LOCK_log before calling this function.
5699     This lock will be released before return! That's required by
5700     THD::enter_cond() (see NOTES in sql_class.h).
5701 */
5702 
wait_for_update_relay_log(THD * thd)5703 void MYSQL_BIN_LOG::wait_for_update_relay_log(THD* thd)
5704 {
5705   const char *old_msg;
5706   DBUG_ENTER("wait_for_update_relay_log");
5707 
5708   old_msg= thd->enter_cond(&update_cond, &LOCK_log,
5709                            "Slave has read all relay log; "
5710                            "waiting for the slave I/O "
5711                            "thread to update it" );
5712   mysql_cond_wait(&update_cond, &LOCK_log);
5713   thd->exit_cond(old_msg);
5714   DBUG_VOID_RETURN;
5715 }
5716 
5717 /**
5718   Wait until we get a signal that the binary log has been updated.
5719   Applies to master only.
5720 
5721   NOTES
5722   @param[in] thd        a THD struct
5723   @param[in] timeout    a pointer to a timespec;
5724                         NULL means to wait w/o timeout.
5725   @retval    0          if got signalled on update
5726   @retval    non-0      if wait timeout elapsed
5727   @note
5728     LOCK_log must be taken before calling this function.
5729     LOCK_log is being released while the thread is waiting.
5730     LOCK_log is released by the caller.
5731 */
5732 
wait_for_update_bin_log(THD * thd,const struct timespec * timeout)5733 int MYSQL_BIN_LOG::wait_for_update_bin_log(THD* thd,
5734                                            const struct timespec *timeout)
5735 {
5736   int ret= 0;
5737   DBUG_ENTER("wait_for_update_bin_log");
5738 
5739   if (!timeout)
5740     mysql_cond_wait(&update_cond, &LOCK_log);
5741   else
5742     ret= mysql_cond_timedwait(&update_cond, &LOCK_log,
5743                               const_cast<struct timespec *>(timeout));
5744   DBUG_RETURN(ret);
5745 }
5746 
5747 
5748 /**
5749   Close the log file.
5750 
5751   @param exiting     Bitmask for one or more of the following bits:
5752           - LOG_CLOSE_INDEX : if we should close the index file
5753           - LOG_CLOSE_TO_BE_OPENED : if we intend to call open
5754                                      at once after close.
5755           - LOG_CLOSE_STOP_EVENT : write a 'stop' event to the log
5756 
5757   @note
5758     One can do an open on the object at once after doing a close.
5759     The internal structures are not freed until cleanup() is called
5760 */
5761 
close(uint exiting)5762 void MYSQL_BIN_LOG::close(uint exiting)
5763 {					// One can't set log_type here!
5764   DBUG_ENTER("MYSQL_BIN_LOG::close");
5765   DBUG_PRINT("enter",("exiting: %d", (int) exiting));
5766   if (log_state == LOG_OPENED)
5767   {
5768 #ifdef HAVE_REPLICATION
5769     if (log_type == LOG_BIN && !no_auto_events &&
5770 	(exiting & LOG_CLOSE_STOP_EVENT))
5771     {
5772       Stop_log_event s;
5773       s.write(&log_file);
5774       bytes_written+= s.data_written;
5775       signal_update();
5776     }
5777 #endif /* HAVE_REPLICATION */
5778 
5779     /* don't pwrite in a file opened with O_APPEND - it doesn't work */
5780     if (log_file.type == WRITE_CACHE && log_type == LOG_BIN)
5781     {
5782       my_off_t offset= BIN_LOG_HEADER_SIZE + FLAGS_OFFSET;
5783       my_off_t org_position= mysql_file_tell(log_file.file, MYF(0));
5784       uchar flags= 0;            // clearing LOG_EVENT_BINLOG_IN_USE_F
5785       mysql_file_pwrite(log_file.file, &flags, 1, offset, MYF(0));
5786       /*
5787         Restore position so that anything we have in the IO_cache is written
5788         to the correct position.
5789         We need the seek here, as mysql_file_pwrite() is not guaranteed to keep the
5790         original position on system that doesn't support pwrite().
5791       */
5792       mysql_file_seek(log_file.file, org_position, MY_SEEK_SET, MYF(0));
5793     }
5794 
5795     /* this will cleanup IO_CACHE, sync and close the file */
5796     MYSQL_LOG::close(exiting);
5797   }
5798 
5799   /*
5800     The following test is needed even if is_open() is not set, as we may have
5801     called a not complete close earlier and the index file is still open.
5802   */
5803 
5804   if ((exiting & LOG_CLOSE_INDEX) && my_b_inited(&index_file))
5805   {
5806     end_io_cache(&index_file);
5807     if (mysql_file_close(index_file.file, MYF(0)) < 0 && ! write_error)
5808     {
5809       write_error= 1;
5810       sql_print_error(ER(ER_ERROR_ON_WRITE), index_file_name, errno);
5811     }
5812   }
5813   log_state= (exiting & LOG_CLOSE_TO_BE_OPENED) ? LOG_TO_BE_OPENED : LOG_CLOSED;
5814   my_free(name);
5815   name= NULL;
5816   DBUG_VOID_RETURN;
5817 }
5818 
5819 
set_max_size(ulong max_size_arg)5820 void MYSQL_BIN_LOG::set_max_size(ulong max_size_arg)
5821 {
5822   /*
5823     We need to take locks, otherwise this may happen:
5824     new_file() is called, calls open(old_max_size), then before open() starts,
5825     set_max_size() sets max_size to max_size_arg, then open() starts and
5826     uses the old_max_size argument, so max_size_arg has been overwritten and
5827     it's like if the SET command was never run.
5828   */
5829   DBUG_ENTER("MYSQL_BIN_LOG::set_max_size");
5830   mysql_mutex_lock(&LOCK_log);
5831   if (is_open())
5832     max_size= max_size_arg;
5833   mysql_mutex_unlock(&LOCK_log);
5834   DBUG_VOID_RETURN;
5835 }
5836 
5837 
5838 /**
5839   Check if a string is a valid number.
5840 
5841   @param str			String to test
5842   @param res			Store value here
5843   @param allow_wildcards	Set to 1 if we should ignore '%' and '_'
5844 
5845   @note
5846     For the moment the allow_wildcards argument is not used
5847     Should be move to some other file.
5848 
5849   @retval
5850     1	String is a number
5851   @retval
5852     0	String is not a number
5853 */
5854 
test_if_number(register const char * str,ulong * res,bool allow_wildcards)5855 static bool test_if_number(register const char *str,
5856 			   ulong *res, bool allow_wildcards)
5857 {
5858   reg2 int flag;
5859   const char *start;
5860   DBUG_ENTER("test_if_number");
5861 
5862   flag=0; start=str;
5863   while (*str++ == ' ') ;
5864   if (*--str == '-' || *str == '+')
5865     str++;
5866   while (my_isdigit(files_charset_info,*str) ||
5867 	 (allow_wildcards && (*str == wild_many || *str == wild_one)))
5868   {
5869     flag=1;
5870     str++;
5871   }
5872   if (*str == '.')
5873   {
5874     for (str++ ;
5875 	 my_isdigit(files_charset_info,*str) ||
5876 	   (allow_wildcards && (*str == wild_many || *str == wild_one)) ;
5877 	 str++, flag=1) ;
5878   }
5879   if (*str != 0 || flag == 0)
5880     DBUG_RETURN(0);
5881   if (res)
5882     *res=atol(start);
5883   DBUG_RETURN(1);			/* Number ok */
5884 } /* test_if_number */
5885 
5886 
sql_perror(const char * message)5887 void sql_perror(const char *message)
5888 {
5889 #ifdef HAVE_STRERROR
5890   sql_print_error("%s: %s",message, strerror(errno));
5891 #else
5892   perror(message);
5893 #endif
5894 }
5895 
5896 
5897 /*
5898   Change the file associated with two output streams. Used to
5899   redirect stdout and stderr to a file. The streams are reopened
5900   only for appending (writing at end of file).
5901 */
reopen_fstreams(const char * filename,FILE * outstream,FILE * errstream)5902 extern "C" my_bool reopen_fstreams(const char *filename,
5903                                    FILE *outstream, FILE *errstream)
5904 {
5905   if (outstream && !my_freopen(filename, "a", outstream))
5906     return TRUE;
5907 
5908   if (errstream && !my_freopen(filename, "a", errstream))
5909     return TRUE;
5910 
5911   /* The error stream must be unbuffered. */
5912   if (errstream)
5913     setbuf(errstream, NULL);
5914 
5915   return FALSE;
5916 }
5917 
5918 
5919 /*
5920   Unfortunately, there seems to be no good way
5921   to restore the original streams upon failure.
5922 */
redirect_std_streams(const char * file)5923 static bool redirect_std_streams(const char *file)
5924 {
5925   if (reopen_fstreams(file, stdout, stderr))
5926     return TRUE;
5927 
5928   setbuf(stderr, NULL);
5929   return FALSE;
5930 }
5931 
5932 
flush_error_log()5933 bool flush_error_log()
5934 {
5935   bool result= 0;
5936   if (opt_error_log)
5937   {
5938     mysql_mutex_lock(&LOCK_error_log);
5939     if (redirect_std_streams(log_error_file))
5940       result= 1;
5941     mysql_mutex_unlock(&LOCK_error_log);
5942   }
5943   return result;
5944 }
5945 
signal_update()5946 void MYSQL_BIN_LOG::signal_update()
5947 {
5948   DBUG_ENTER("MYSQL_BIN_LOG::signal_update");
5949   signal_cnt++;
5950   mysql_cond_broadcast(&update_cond);
5951   DBUG_VOID_RETURN;
5952 }
5953 
5954 #ifdef _WIN32
print_buffer_to_nt_eventlog(enum loglevel level,char * buff,size_t length,size_t buffLen)5955 static void print_buffer_to_nt_eventlog(enum loglevel level, char *buff,
5956                                         size_t length, size_t buffLen)
5957 {
5958   HANDLE event;
5959   char   *buffptr= buff;
5960   DBUG_ENTER("print_buffer_to_nt_eventlog");
5961 
5962   /* Add ending CR/LF's to string, overwrite last chars if necessary */
5963   strmov(buffptr+min(length, buffLen-5), "\r\n\r\n");
5964 
5965   setup_windows_event_source();
5966   if ((event= RegisterEventSource(NULL,"MySQL")))
5967   {
5968     switch (level) {
5969       case ERROR_LEVEL:
5970         ReportEvent(event, EVENTLOG_ERROR_TYPE, 0, MSG_DEFAULT, NULL, 1, 0,
5971                     (LPCSTR*)&buffptr, NULL);
5972         break;
5973       case WARNING_LEVEL:
5974         ReportEvent(event, EVENTLOG_WARNING_TYPE, 0, MSG_DEFAULT, NULL, 1, 0,
5975                     (LPCSTR*) &buffptr, NULL);
5976         break;
5977       case INFORMATION_LEVEL:
5978         ReportEvent(event, EVENTLOG_INFORMATION_TYPE, 0, MSG_DEFAULT, NULL, 1,
5979                     0, (LPCSTR*) &buffptr, NULL);
5980         break;
5981     }
5982     DeregisterEventSource(event);
5983   }
5984 
5985   DBUG_VOID_RETURN;
5986 }
5987 #endif /* _WIN32 */
5988 
5989 
5990 #ifndef EMBEDDED_LIBRARY
print_buffer_to_file(enum loglevel level,const char * buffer,size_t length)5991 static void print_buffer_to_file(enum loglevel level, const char *buffer,
5992                                  size_t length)
5993 {
5994   time_t skr;
5995   struct tm tm_tmp;
5996   struct tm *start;
5997   DBUG_ENTER("print_buffer_to_file");
5998   DBUG_PRINT("enter",("buffer: %s", buffer));
5999 
6000   mysql_mutex_lock(&LOCK_error_log);
6001 
6002   skr= my_time(0);
6003   localtime_r(&skr, &tm_tmp);
6004   start=&tm_tmp;
6005 
6006   fprintf(stderr, "%02d%02d%02d %2d:%02d:%02d [%s] %.*s\n",
6007           start->tm_year % 100,
6008           start->tm_mon+1,
6009           start->tm_mday,
6010           start->tm_hour,
6011           start->tm_min,
6012           start->tm_sec,
6013           (level == ERROR_LEVEL ? "ERROR" : level == WARNING_LEVEL ?
6014            "Warning" : "Note"),
6015           (int) length, buffer);
6016 
6017   fflush(stderr);
6018 
6019   mysql_mutex_unlock(&LOCK_error_log);
6020   DBUG_VOID_RETURN;
6021 }
6022 
6023 /**
6024   Prints a printf style message to the error log and, under NT, to the
6025   Windows event log.
6026 
6027   This function prints the message into a buffer and then sends that buffer
6028   to other functions to write that message to other logging sources.
6029 
6030   @param level          The level of the msg significance
6031   @param format         Printf style format of message
6032   @param args           va_list list of arguments for the message
6033 
6034   @returns
6035     The function always returns 0. The return value is present in the
6036     signature to be compatible with other logging routines, which could
6037     return an error (e.g. logging to the log tables)
6038 */
vprint_msg_to_log(enum loglevel level,const char * format,va_list args)6039 int vprint_msg_to_log(enum loglevel level, const char *format, va_list args)
6040 {
6041   char   buff[1024];
6042   size_t length;
6043   DBUG_ENTER("vprint_msg_to_log");
6044 
6045   length= my_vsnprintf(buff, sizeof(buff), format, args);
6046   print_buffer_to_file(level, buff, length);
6047 
6048 #ifdef _WIN32
6049   print_buffer_to_nt_eventlog(level, buff, length, sizeof(buff));
6050 #endif
6051 
6052   DBUG_RETURN(0);
6053 }
6054 #endif /* EMBEDDED_LIBRARY */
6055 
6056 
sql_print_error(const char * format,...)6057 void sql_print_error(const char *format, ...)
6058 {
6059   va_list args;
6060   DBUG_ENTER("sql_print_error");
6061 
6062   va_start(args, format);
6063   error_log_print(ERROR_LEVEL, format, args);
6064   va_end(args);
6065 
6066   DBUG_VOID_RETURN;
6067 }
6068 
6069 
sql_print_warning(const char * format,...)6070 void sql_print_warning(const char *format, ...)
6071 {
6072   va_list args;
6073   DBUG_ENTER("sql_print_warning");
6074 
6075   va_start(args, format);
6076   error_log_print(WARNING_LEVEL, format, args);
6077   va_end(args);
6078 
6079   DBUG_VOID_RETURN;
6080 }
6081 
6082 
sql_print_information(const char * format,...)6083 void sql_print_information(const char *format, ...)
6084 {
6085   va_list args;
6086   DBUG_ENTER("sql_print_information");
6087 
6088   va_start(args, format);
6089   error_log_print(INFORMATION_LEVEL, format, args);
6090   va_end(args);
6091 
6092   DBUG_VOID_RETURN;
6093 }
6094 
6095 
6096 /********* transaction coordinator log for 2pc - mmap() based solution *******/
6097 
6098 /*
6099   the log consists of a file, mmapped to a memory.
6100   file is divided on pages of tc_log_page_size size.
6101   (usable size of the first page is smaller because of log header)
6102   there's PAGE control structure for each page
6103   each page (or rather PAGE control structure) can be in one of three
6104   states - active, syncing, pool.
6105   there could be only one page in active or syncing states,
6106   but many in pool - pool is fifo queue.
6107   usual lifecycle of a page is pool->active->syncing->pool
6108   "active" page - is a page where new xid's are logged.
6109   the page stays active as long as syncing slot is taken.
6110   "syncing" page is being synced to disk. no new xid can be added to it.
6111   when the sync is done the page is moved to a pool and an active page
6112   becomes "syncing".
6113 
6114   the result of such an architecture is a natural "commit grouping" -
6115   If commits are coming faster than the system can sync, they do not
6116   stall. Instead, all commit that came since the last sync are
6117   logged to the same page, and they all are synced with the next -
6118   one - sync. Thus, thought individual commits are delayed, throughput
6119   is not decreasing.
6120 
6121   when a xid is added to an active page, the thread of this xid waits
6122   for a page's condition until the page is synced. when syncing slot
6123   becomes vacant one of these waiters is awaken to take care of syncing.
6124   it syncs the page and signals all waiters that the page is synced.
6125   PAGE::waiters is used to count these waiters, and a page may never
6126   become active again until waiters==0 (that is all waiters from the
6127   previous sync have noticed the sync was completed)
6128 
6129   note, that the page becomes "dirty" and has to be synced only when a
6130   new xid is added into it. Removing a xid from a page does not make it
6131   dirty - we don't sync removals to disk.
6132 */
6133 
6134 ulong tc_log_page_waits= 0;
6135 
6136 #ifdef HAVE_MMAP
6137 
6138 #define TC_LOG_HEADER_SIZE (sizeof(tc_log_magic)+1)
6139 
6140 static const char tc_log_magic[]={(char) 254, 0x23, 0x05, 0x74};
6141 
6142 ulong opt_tc_log_size= TC_LOG_MIN_SIZE;
6143 ulong tc_log_max_pages_used=0, tc_log_page_size=0, tc_log_cur_pages_used=0;
6144 
open(const char * opt_name)6145 int TC_LOG_MMAP::open(const char *opt_name)
6146 {
6147   uint i;
6148   bool crashed=FALSE;
6149   PAGE *pg;
6150 
6151   DBUG_ASSERT(total_ha_2pc > 1);
6152   DBUG_ASSERT(opt_name && opt_name[0]);
6153 
6154   tc_log_page_size= my_getpagesize();
6155   DBUG_ASSERT(TC_LOG_PAGE_SIZE % tc_log_page_size == 0);
6156 
6157   fn_format(logname,opt_name,mysql_data_home,"",MY_UNPACK_FILENAME);
6158   if ((fd= mysql_file_open(key_file_tclog, logname, O_RDWR, MYF(0))) < 0)
6159   {
6160     if (my_errno != ENOENT)
6161       goto err;
6162     if (using_heuristic_recover())
6163       return 1;
6164     if ((fd= mysql_file_create(key_file_tclog, logname, CREATE_MODE,
6165                                O_RDWR, MYF(MY_WME))) < 0)
6166       goto err;
6167     inited=1;
6168     file_length= opt_tc_log_size;
6169     if (mysql_file_chsize(fd, file_length, 0, MYF(MY_WME)))
6170       goto err;
6171   }
6172   else
6173   {
6174     inited= 1;
6175     crashed= TRUE;
6176     sql_print_information("Recovering after a crash using %s", opt_name);
6177     if (tc_heuristic_recover)
6178     {
6179       sql_print_error("Cannot perform automatic crash recovery when "
6180                       "--tc-heuristic-recover is used");
6181       goto err;
6182     }
6183     file_length= mysql_file_seek(fd, 0L, MY_SEEK_END, MYF(MY_WME+MY_FAE));
6184     if (file_length == MY_FILEPOS_ERROR || file_length % tc_log_page_size)
6185       goto err;
6186   }
6187 
6188   data= (uchar *)my_mmap(0, (size_t)file_length, PROT_READ|PROT_WRITE,
6189                         MAP_NOSYNC|MAP_SHARED, fd, 0);
6190   if (data == MAP_FAILED)
6191   {
6192     my_errno=errno;
6193     goto err;
6194   }
6195   inited=2;
6196 
6197   npages=(uint)file_length/tc_log_page_size;
6198   DBUG_ASSERT(npages >= 3);             // to guarantee non-empty pool
6199   if (!(pages=(PAGE *)my_malloc(npages*sizeof(PAGE), MYF(MY_WME|MY_ZEROFILL))))
6200     goto err;
6201   inited=3;
6202   for (pg=pages, i=0; i < npages; i++, pg++)
6203   {
6204     pg->next=pg+1;
6205     pg->waiters=0;
6206     pg->state=PS_POOL;
6207     mysql_mutex_init(key_PAGE_lock, &pg->lock, MY_MUTEX_INIT_FAST);
6208     mysql_cond_init(key_PAGE_cond, &pg->cond, 0);
6209     pg->start=(my_xid *)(data + i*tc_log_page_size);
6210     pg->end=(my_xid *)(pg->start + tc_log_page_size);
6211     pg->size=pg->free=tc_log_page_size/sizeof(my_xid);
6212   }
6213   pages[0].size=pages[0].free=
6214                 (tc_log_page_size-TC_LOG_HEADER_SIZE)/sizeof(my_xid);
6215   pages[0].start=pages[0].end-pages[0].size;
6216   pages[npages-1].next=0;
6217   inited=4;
6218 
6219   if (crashed && recover())
6220       goto err;
6221 
6222   memcpy(data, tc_log_magic, sizeof(tc_log_magic));
6223   data[sizeof(tc_log_magic)]= (uchar)total_ha_2pc;
6224   my_msync(fd, data, tc_log_page_size, MS_SYNC);
6225   inited=5;
6226 
6227   mysql_mutex_init(key_LOCK_sync, &LOCK_sync, MY_MUTEX_INIT_FAST);
6228   mysql_mutex_init(key_LOCK_active, &LOCK_active, MY_MUTEX_INIT_FAST);
6229   mysql_mutex_init(key_LOCK_pool, &LOCK_pool, MY_MUTEX_INIT_FAST);
6230   mysql_cond_init(key_COND_active, &COND_active, 0);
6231   mysql_cond_init(key_COND_pool, &COND_pool, 0);
6232 
6233   inited=6;
6234 
6235   syncing= 0;
6236   active=pages;
6237   pool=pages+1;
6238   pool_last=pages+npages-1;
6239 
6240   return 0;
6241 
6242 err:
6243   close();
6244   return 1;
6245 }
6246 
6247 /**
6248   there is no active page, let's got one from the pool.
6249 
6250   Two strategies here:
6251     -# take the first from the pool
6252     -# if there're waiters - take the one with the most free space.
6253 
6254   @todo
6255     TODO page merging. try to allocate adjacent page first,
6256     so that they can be flushed both in one sync
6257 */
6258 
get_active_from_pool()6259 void TC_LOG_MMAP::get_active_from_pool()
6260 {
6261   PAGE **p, **best_p=0;
6262   int best_free;
6263 
6264   if (syncing)
6265     mysql_mutex_lock(&LOCK_pool);
6266 
6267   do
6268   {
6269     best_p= p= &pool;
6270     if ((*p)->waiters == 0) // can the first page be used ?
6271       break;                // yes - take it.
6272 
6273     best_free=0;            // no - trying second strategy
6274     for (p=&(*p)->next; *p; p=&(*p)->next)
6275     {
6276       if ((*p)->waiters == 0 && (*p)->free > best_free)
6277       {
6278         best_free=(*p)->free;
6279         best_p=p;
6280       }
6281     }
6282   }
6283   while ((*best_p == 0 || best_free == 0) && overflow());
6284 
6285   active=*best_p;
6286   if (active->free == active->size) // we've chosen an empty page
6287   {
6288     tc_log_cur_pages_used++;
6289     set_if_bigger(tc_log_max_pages_used, tc_log_cur_pages_used);
6290   }
6291 
6292   if ((*best_p)->next)              // unlink the page from the pool
6293     *best_p=(*best_p)->next;
6294   else
6295     pool_last=*best_p;
6296 
6297   if (syncing)
6298     mysql_mutex_unlock(&LOCK_pool);
6299 }
6300 
6301 /**
6302   @todo
6303   perhaps, increase log size ?
6304 */
overflow()6305 int TC_LOG_MMAP::overflow()
6306 {
6307   /*
6308     simple overflow handling - just wait
6309     TODO perhaps, increase log size ?
6310     let's check the behaviour of tc_log_page_waits first
6311   */
6312   tc_log_page_waits++;
6313   mysql_cond_wait(&COND_pool, &LOCK_pool);
6314   return 1; // always return 1
6315 }
6316 
6317 /**
6318   Record that transaction XID is committed on the persistent storage.
6319 
6320     This function is called in the middle of two-phase commit:
6321     First all resources prepare the transaction, then tc_log->log() is called,
6322     then all resources commit the transaction, then tc_log->unlog() is called.
6323 
6324     All access to active page is serialized but it's not a problem, as
6325     we're assuming that fsync() will be a main bottleneck.
6326     That is, parallelizing writes to log pages we'll decrease number of
6327     threads waiting for a page, but then all these threads will be waiting
6328     for a fsync() anyway
6329 
6330    If tc_log == MYSQL_LOG then tc_log writes transaction to binlog and
6331    records XID in a special Xid_log_event.
6332    If tc_log = TC_LOG_MMAP then xid is written in a special memory-mapped
6333    log.
6334 
6335   @retval
6336     0  - error
6337   @retval
6338     \# - otherwise, "cookie", a number that will be passed as an argument
6339     to unlog() call. tc_log can define it any way it wants,
6340     and use for whatever purposes. TC_LOG_MMAP sets it
6341     to the position in memory where xid was logged to.
6342 */
6343 
log_xid(THD * thd,my_xid xid)6344 int TC_LOG_MMAP::log_xid(THD *thd, my_xid xid)
6345 {
6346   int err;
6347   PAGE *p;
6348   ulong cookie;
6349 
6350   mysql_mutex_lock(&LOCK_active);
6351 
6352   /*
6353     if active page is full - just wait...
6354     frankly speaking, active->free here accessed outside of mutex
6355     protection, but it's safe, because it only means we may miss an
6356     unlog() for the active page, and we're not waiting for it here -
6357     unlog() does not signal COND_active.
6358   */
6359   while (unlikely(active && active->free == 0))
6360     mysql_cond_wait(&COND_active, &LOCK_active);
6361 
6362   /* no active page ? take one from the pool */
6363   if (active == 0)
6364     get_active_from_pool();
6365 
6366   p=active;
6367   mysql_mutex_lock(&p->lock);
6368 
6369   /* searching for an empty slot */
6370   while (*p->ptr)
6371   {
6372     p->ptr++;
6373     DBUG_ASSERT(p->ptr < p->end);               // because p->free > 0
6374   }
6375 
6376   /* found! store xid there and mark the page dirty */
6377   cookie= (ulong)((uchar *)p->ptr - data);      // can never be zero
6378   *p->ptr++= xid;
6379   p->free--;
6380   p->state= PS_DIRTY;
6381 
6382   /* to sync or not to sync - this is the question */
6383   mysql_mutex_unlock(&LOCK_active);
6384   mysql_mutex_lock(&LOCK_sync);
6385   mysql_mutex_unlock(&p->lock);
6386 
6387   if (syncing)
6388   {                                          // somebody's syncing. let's wait
6389     p->waiters++;
6390     /*
6391       note - it must be while (), not do ... while () here
6392       as p->state may be not PS_DIRTY when we come here
6393     */
6394     while (p->state == PS_DIRTY && syncing)
6395       mysql_cond_wait(&p->cond, &LOCK_sync);
6396     p->waiters--;
6397     err= p->state == PS_ERROR;
6398     if (p->state != PS_DIRTY)                   // page was synced
6399     {
6400       if (p->waiters == 0)
6401         mysql_cond_signal(&COND_pool);       // in case somebody's waiting
6402       mysql_mutex_unlock(&LOCK_sync);
6403       goto done;                             // we're done
6404     }
6405   }                                          // page was not synced! do it now
6406   DBUG_ASSERT(active == p && syncing == 0);
6407   mysql_mutex_lock(&LOCK_active);
6408   syncing=p;                                 // place is vacant - take it
6409   active=0;                                  // page is not active anymore
6410   mysql_cond_broadcast(&COND_active);        // in case somebody's waiting
6411   mysql_mutex_unlock(&LOCK_active);
6412   mysql_mutex_unlock(&LOCK_sync);
6413   err= sync();
6414 
6415 done:
6416   return err ? 0 : cookie;
6417 }
6418 
sync()6419 int TC_LOG_MMAP::sync()
6420 {
6421   int err;
6422 
6423   DBUG_ASSERT(syncing != active);
6424 
6425   /*
6426     sit down and relax - this can take a while...
6427     note - no locks are held at this point
6428   */
6429   err= my_msync(fd, syncing->start, 1, MS_SYNC);
6430 
6431   /* page is synced. let's move it to the pool */
6432   mysql_mutex_lock(&LOCK_pool);
6433   pool_last->next=syncing;
6434   pool_last=syncing;
6435   syncing->next=0;
6436   syncing->state= err ? PS_ERROR : PS_POOL;
6437   mysql_cond_broadcast(&syncing->cond);      // signal "sync done"
6438   mysql_cond_signal(&COND_pool);             // in case somebody's waiting
6439   mysql_mutex_unlock(&LOCK_pool);
6440 
6441   /* marking 'syncing' slot free */
6442   mysql_mutex_lock(&LOCK_sync);
6443   syncing=0;
6444   mysql_cond_signal(&active->cond);        // wake up a new syncer
6445   mysql_mutex_unlock(&LOCK_sync);
6446   return err;
6447 }
6448 
6449 /**
6450   erase xid from the page, update page free space counters/pointers.
6451   cookie points directly to the memory where xid was logged.
6452 */
6453 
unlog(ulong cookie,my_xid xid)6454 int TC_LOG_MMAP::unlog(ulong cookie, my_xid xid)
6455 {
6456   PAGE *p=pages+(cookie/tc_log_page_size);
6457   my_xid *x=(my_xid *)(data+cookie);
6458 
6459   DBUG_ASSERT(*x == xid);
6460   DBUG_ASSERT(x >= p->start && x < p->end);
6461   *x=0;
6462 
6463   mysql_mutex_lock(&p->lock);
6464   p->free++;
6465   DBUG_ASSERT(p->free <= p->size);
6466   set_if_smaller(p->ptr, x);
6467   if (p->free == p->size)               // the page is completely empty
6468     statistic_decrement(tc_log_cur_pages_used, &LOCK_status);
6469   if (p->waiters == 0)                 // the page is in pool and ready to rock
6470     mysql_cond_signal(&COND_pool);     // ping ... for overflow()
6471   mysql_mutex_unlock(&p->lock);
6472   return 0;
6473 }
6474 
close()6475 void TC_LOG_MMAP::close()
6476 {
6477   uint i;
6478   switch (inited) {
6479   case 6:
6480     mysql_mutex_destroy(&LOCK_sync);
6481     mysql_mutex_destroy(&LOCK_active);
6482     mysql_mutex_destroy(&LOCK_pool);
6483     mysql_cond_destroy(&COND_pool);
6484   case 5:
6485     data[0]='A'; // garble the first (signature) byte, in case mysql_file_delete fails
6486   case 4:
6487     for (i=0; i < npages; i++)
6488     {
6489       if (pages[i].ptr == 0)
6490         break;
6491       mysql_mutex_destroy(&pages[i].lock);
6492       mysql_cond_destroy(&pages[i].cond);
6493     }
6494   case 3:
6495     my_free(pages);
6496   case 2:
6497     my_munmap((char*)data, (size_t)file_length);
6498   case 1:
6499     mysql_file_close(fd, MYF(0));
6500   }
6501   if (inited>=5) // cannot do in the switch because of Windows
6502     mysql_file_delete(key_file_tclog, logname, MYF(MY_WME));
6503   inited=0;
6504 }
6505 
recover()6506 int TC_LOG_MMAP::recover()
6507 {
6508   HASH xids;
6509   PAGE *p=pages, *end_p=pages+npages;
6510 
6511   if (memcmp(data, tc_log_magic, sizeof(tc_log_magic)))
6512   {
6513     sql_print_error("Bad magic header in tc log");
6514     goto err1;
6515   }
6516 
6517   /*
6518     the first byte after magic signature is set to current
6519     number of storage engines on startup
6520   */
6521   if (data[sizeof(tc_log_magic)] != total_ha_2pc)
6522   {
6523     sql_print_error("Recovery failed! You must enable "
6524                     "exactly %d storage engines that support "
6525                     "two-phase commit protocol",
6526                     data[sizeof(tc_log_magic)]);
6527     goto err1;
6528   }
6529 
6530   if (my_hash_init(&xids, &my_charset_bin, tc_log_page_size/3, 0,
6531                    sizeof(my_xid), 0, 0, MYF(0)))
6532     goto err1;
6533 
6534   for ( ; p < end_p ; p++)
6535   {
6536     for (my_xid *x=p->start; x < p->end; x++)
6537       if (*x && my_hash_insert(&xids, (uchar *)x))
6538         goto err2; // OOM
6539   }
6540 
6541   if (ha_recover(&xids))
6542     goto err2;
6543 
6544   my_hash_free(&xids);
6545   bzero(data, (size_t)file_length);
6546   return 0;
6547 
6548 err2:
6549   my_hash_free(&xids);
6550 err1:
6551   sql_print_error("Crash recovery failed. Either correct the problem "
6552                   "(if it's, for example, out of memory error) and restart, "
6553                   "or delete tc log and start mysqld with "
6554                   "--tc-heuristic-recover={commit|rollback}");
6555   return 1;
6556 }
6557 #endif
6558 
6559 TC_LOG *tc_log;
6560 TC_LOG_DUMMY tc_log_dummy;
6561 TC_LOG_MMAP  tc_log_mmap;
6562 
6563 /**
6564   Perform heuristic recovery, if --tc-heuristic-recover was used.
6565 
6566   @note
6567     no matter whether heuristic recovery was successful or not
6568     mysqld must exit. So, return value is the same in both cases.
6569 
6570   @retval
6571     0	no heuristic recovery was requested
6572   @retval
6573     1   heuristic recovery was performed
6574 */
6575 
using_heuristic_recover()6576 int TC_LOG::using_heuristic_recover()
6577 {
6578   if (!tc_heuristic_recover)
6579     return 0;
6580 
6581   sql_print_information("Heuristic crash recovery mode");
6582   if (ha_recover(0))
6583     sql_print_error("Heuristic crash recovery failed");
6584   sql_print_information("Please restart mysqld without --tc-heuristic-recover");
6585   return 1;
6586 }
6587 
6588 /****** transaction coordinator log for 2pc - binlog() based solution ******/
6589 #define TC_LOG_BINLOG MYSQL_BIN_LOG
6590 
6591 /**
6592   @todo
6593   keep in-memory list of prepared transactions
6594   (add to list in log(), remove on unlog())
6595   and copy it to the new binlog if rotated
6596   but let's check the behaviour of tc_log_page_waits first!
6597 */
6598 
open(const char * opt_name)6599 int TC_LOG_BINLOG::open(const char *opt_name)
6600 {
6601   LOG_INFO log_info;
6602   int      error= 1;
6603 
6604   DBUG_ASSERT(total_ha_2pc > 1);
6605   DBUG_ASSERT(opt_name && opt_name[0]);
6606 
6607   mysql_mutex_init(key_BINLOG_LOCK_prep_xids,
6608                    &LOCK_prep_xids, MY_MUTEX_INIT_FAST);
6609   mysql_cond_init(key_BINLOG_COND_prep_xids, &COND_prep_xids, 0);
6610 
6611   if (!my_b_inited(&index_file))
6612   {
6613     /* There was a failure to open the index file, can't open the binlog */
6614     cleanup();
6615     return 1;
6616   }
6617 
6618   if (using_heuristic_recover())
6619   {
6620     /* generate a new binlog to mask a corrupted one */
6621     open(opt_name, LOG_BIN, 0, WRITE_CACHE, 0, max_binlog_size, 0, TRUE);
6622     cleanup();
6623     return 1;
6624   }
6625 
6626   if ((error= find_log_pos(&log_info, NullS, 1)))
6627   {
6628     if (error != LOG_INFO_EOF)
6629       sql_print_error("find_log_pos() failed (error: %d)", error);
6630     else
6631       error= 0;
6632     goto err;
6633   }
6634 
6635   {
6636     const char *errmsg;
6637     IO_CACHE    log;
6638     File        file;
6639     Log_event  *ev=0;
6640     Format_description_log_event fdle(BINLOG_VERSION);
6641     char        log_name[FN_REFLEN];
6642 
6643     if (! fdle.is_valid())
6644       goto err;
6645 
6646     do
6647     {
6648       strmake(log_name, log_info.log_file_name, sizeof(log_name)-1);
6649     } while (!(error= find_next_log(&log_info, 1)));
6650 
6651     if (error !=  LOG_INFO_EOF)
6652     {
6653       sql_print_error("find_log_pos() failed (error: %d)", error);
6654       goto err;
6655     }
6656 
6657     if ((file= open_binlog(&log, log_name, &errmsg)) < 0)
6658     {
6659       sql_print_error("%s", errmsg);
6660       goto err;
6661     }
6662 
6663     if ((ev= Log_event::read_log_event(&log, 0, &fdle)) &&
6664         ev->get_type_code() == FORMAT_DESCRIPTION_EVENT &&
6665         ev->flags & LOG_EVENT_BINLOG_IN_USE_F)
6666     {
6667       sql_print_information("Recovering after a crash using %s", opt_name);
6668       error= recover(&log, (Format_description_log_event *)ev);
6669     }
6670     else
6671       error=0;
6672 
6673     delete ev;
6674     end_io_cache(&log);
6675     mysql_file_close(file, MYF(MY_WME));
6676 
6677     if (error)
6678       goto err;
6679   }
6680 
6681 err:
6682   return error;
6683 }
6684 
6685 /** This is called on shutdown, after ha_panic. */
close()6686 void TC_LOG_BINLOG::close()
6687 {
6688   DBUG_ASSERT(prepared_xids==0);
6689   mysql_mutex_destroy(&LOCK_prep_xids);
6690   mysql_cond_destroy(&COND_prep_xids);
6691 }
6692 
6693 /**
6694   @todo
6695   group commit
6696 
6697   @retval
6698     0    error
6699   @retval
6700     1    success
6701 */
log_xid(THD * thd,my_xid xid)6702 int TC_LOG_BINLOG::log_xid(THD *thd, my_xid xid)
6703 {
6704   DBUG_ENTER("TC_LOG_BINLOG::log");
6705   binlog_cache_mngr *cache_mngr=
6706     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
6707   /*
6708     We always commit the entire transaction when writing an XID. Also
6709     note that the return value is inverted.
6710    */
6711   DBUG_RETURN(!binlog_commit_flush_stmt_cache(thd, cache_mngr) &&
6712               !binlog_commit_flush_trx_cache(thd, cache_mngr, xid));
6713 }
6714 
unlog(ulong cookie,my_xid xid)6715 int TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid)
6716 {
6717   DBUG_ENTER("TC_LOG_BINLOG::unlog");
6718   mysql_mutex_lock(&LOCK_prep_xids);
6719   // prepared_xids can be 0 if the transaction had ignorable errors.
6720   DBUG_ASSERT(prepared_xids >= 0);
6721   if (prepared_xids > 0)
6722     prepared_xids--;
6723   if (prepared_xids == 0) {
6724     DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids));
6725     mysql_cond_signal(&COND_prep_xids);
6726   }
6727   mysql_mutex_unlock(&LOCK_prep_xids);
6728   DBUG_RETURN(rotate_and_purge(0));     // as ::write() did not rotate
6729 }
6730 
recover(IO_CACHE * log,Format_description_log_event * fdle)6731 int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle)
6732 {
6733   Log_event  *ev;
6734   HASH xids;
6735   MEM_ROOT mem_root;
6736 
6737   if (! fdle->is_valid() ||
6738       my_hash_init(&xids, &my_charset_bin, TC_LOG_PAGE_SIZE/3, 0,
6739                    sizeof(my_xid), 0, 0, MYF(0)))
6740     goto err1;
6741 
6742   init_alloc_root(&mem_root, TC_LOG_PAGE_SIZE, TC_LOG_PAGE_SIZE);
6743 
6744   fdle->flags&= ~LOG_EVENT_BINLOG_IN_USE_F; // abort on the first error
6745 
6746   while ((ev= Log_event::read_log_event(log,0,fdle)) && ev->is_valid())
6747   {
6748     if (ev->get_type_code() == XID_EVENT)
6749     {
6750       Xid_log_event *xev=(Xid_log_event *)ev;
6751       uchar *x= (uchar *) memdup_root(&mem_root, (uchar*) &xev->xid,
6752                                       sizeof(xev->xid));
6753       if (!x || my_hash_insert(&xids, x))
6754         goto err2;
6755     }
6756     delete ev;
6757   }
6758 
6759   if (ha_recover(&xids))
6760     goto err2;
6761 
6762   free_root(&mem_root, MYF(0));
6763   my_hash_free(&xids);
6764   return 0;
6765 
6766 err2:
6767   free_root(&mem_root, MYF(0));
6768   my_hash_free(&xids);
6769 err1:
6770   sql_print_error("Crash recovery failed. Either correct the problem "
6771                   "(if it's, for example, out of memory error) and restart, "
6772                   "or delete (or rename) binary log and start mysqld with "
6773                   "--tc-heuristic-recover={commit|rollback}");
6774   return 1;
6775 }
6776 
6777 
6778 #ifdef INNODB_COMPATIBILITY_HOOKS
6779 /**
6780   Get the file name of the MySQL binlog.
6781   @return the name of the binlog file
6782 */
6783 extern "C"
mysql_bin_log_file_name(void)6784 const char* mysql_bin_log_file_name(void)
6785 {
6786   return mysql_bin_log.get_log_fname();
6787 }
6788 /**
6789   Get the current position of the MySQL binlog.
6790   @return byte offset from the beginning of the binlog
6791 */
6792 extern "C"
mysql_bin_log_file_pos(void)6793 ulonglong mysql_bin_log_file_pos(void)
6794 {
6795   return (ulonglong) mysql_bin_log.get_log_file()->pos_in_file;
6796 }
6797 #endif /* INNODB_COMPATIBILITY_HOOKS */
6798 
6799 
6800 struct st_mysql_storage_engine binlog_storage_engine=
6801 { MYSQL_HANDLERTON_INTERFACE_VERSION };
6802 
mysql_declare_plugin(binlog)6803 mysql_declare_plugin(binlog)
6804 {
6805   MYSQL_STORAGE_ENGINE_PLUGIN,
6806   &binlog_storage_engine,
6807   "binlog",
6808   "MySQL AB",
6809   "This is a pseudo storage engine to represent the binlog in a transaction",
6810   PLUGIN_LICENSE_GPL,
6811   binlog_init, /* Plugin Init */
6812   NULL, /* Plugin Deinit */
6813   0x0100 /* 1.0 */,
6814   NULL,                       /* status variables                */
6815   NULL,                       /* system variables                */
6816   NULL,                       /* config options                  */
6817   0,                          /* flags                           */
6818 }
6819 mysql_declare_plugin_end;
6820