You need to sign in or sign up before continuing.
log.cc 25.7 KB
Newer Older
unknown's avatar
unknown committed
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18
/* Copyright (C) 2000 MySQL AB & MySQL Finland AB & TCX DataKonsult AB
   
   This program is free software; you can redistribute it and/or modify
   it under the terms of the GNU General Public License as published by
   the Free Software Foundation; either version 2 of the License, or
   (at your option) any later version.
   
   This program is distributed in the hope that it will be useful,
   but WITHOUT ANY WARRANTY; without even the implied warranty of
   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
   GNU General Public License for more details.
   
   You should have received a copy of the GNU General Public License
   along with this program; if not, write to the Free Software
   Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA */


/* logging of commands */
19
/* TODO: Abort logging when we get an error in reading or writing log files */
unknown's avatar
unknown committed
20

21 22 23 24
#ifdef __EMX__
#include <io.h>
#endif

unknown's avatar
unknown committed
25 26
#include "mysql_priv.h"
#include "sql_acl.h"
unknown's avatar
unknown committed
27
#include "sql_repl.h"
unknown's avatar
unknown committed
28 29 30 31 32 33 34

#include <my_dir.h>
#include <stdarg.h>
#include <m_ctype.h>				// For test_if_number

MYSQL_LOG mysql_log,mysql_update_log,mysql_slow_log,mysql_bin_log;
extern I_List<i_string> binlog_do_db, binlog_ignore_db;
35
extern ulong max_binlog_size;
unknown's avatar
unknown committed
36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58

static bool test_if_number(const char *str,
			   long *res, bool allow_wildcards);

/****************************************************************************
** Find a uniq filename for 'filename.#'.
** Set # to a number as low as possible
** returns != 0 if not possible to get uniq filename
****************************************************************************/

static int find_uniq_filename(char *name)
{
  long		number;
  uint		i,length;
  char		buff[FN_REFLEN];
  struct st_my_dir *dir_info;
  reg1 struct fileinfo *file_info;
  ulong		max_found=0;
  DBUG_ENTER("find_uniq_filename");

  length=dirname_part(buff,name);
  char *start=name+length,*end=strend(start);
  *end='.';
unknown's avatar
unknown committed
59
  length= (uint) (end-start+1);
unknown's avatar
unknown committed
60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81

  if (!(dir_info = my_dir(buff,MYF(MY_DONT_SORT))))
  {						// This shouldn't happen
    strmov(end,".1");				// use name+1
    DBUG_RETURN(0);
  }
  file_info= dir_info->dir_entry;
  for (i=dir_info->number_off_files ; i-- ; file_info++)
  {
    if (bcmp(file_info->name,start,length) == 0 &&
	test_if_number(file_info->name+length, &number,0))
    {
      set_if_bigger(max_found,(ulong) number);
    }
  }
  my_dirend(dir_info);

  *end++='.';
  sprintf(end,"%03ld",max_found+1);
  DBUG_RETURN(0);
}

unknown's avatar
unknown committed
82
MYSQL_LOG::MYSQL_LOG(): last_time(0), query_start(0),index_file(-1),
83
			name(0), log_type(LOG_CLOSED),write_error(0),
84 85
			inited(0), log_seq(1), file_id(1),no_rotate(0),
			need_start_event(1)
unknown's avatar
unknown committed
86 87 88 89 90
{
  /*
    We don't want to intialize LOCK_Log here as the thread system may
    not have been initailized yet. We do it instead at 'open'.
  */
91 92
  index_file_name[0] = 0;
  bzero((char*) &log_file,sizeof(log_file));
unknown's avatar
unknown committed
93 94 95 96 97
}

MYSQL_LOG::~MYSQL_LOG()
{
  if (inited)
98 99 100 101
  {
    (void) pthread_mutex_destroy(&LOCK_log);
    (void) pthread_mutex_destroy(&LOCK_index);
  }
unknown's avatar
unknown committed
102 103 104 105 106
}

void MYSQL_LOG::set_index_file_name(const char* index_file_name)
{
  if (index_file_name)
107
    fn_format(this->index_file_name,index_file_name,mysql_data_home,".index",
unknown's avatar
unknown committed
108 109 110 111 112
	      4);
  else
    this->index_file_name[0] = 0;
}

113

unknown's avatar
unknown committed
114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132
int MYSQL_LOG::generate_new_name(char *new_name, const char *log_name)
{      
  if (log_type == LOG_NORMAL)
    fn_format(new_name,log_name,mysql_data_home,"",4);
  else
  {
    fn_format(new_name,log_name,mysql_data_home,"",4);
    if (!fn_ext(log_name)[0])
    {
      if (find_uniq_filename(new_name))
      {
	sql_print_error(ER(ER_NO_UNIQUE_LOGFILE), log_name);
	return 1;
      }
    }
  }
  return 0;
}

133 134 135 136 137 138 139
bool MYSQL_LOG::open_index( int options)
{
  return (index_file < 0 && 
	 (index_file = my_open(index_file_name, options | O_BINARY ,
			       MYF(MY_WME))) < 0);
}

140 141
void MYSQL_LOG::init(enum_log_type log_type_arg,
		     enum cache_type io_cache_type_arg)
142 143
{
  log_type = log_type_arg;
144
  io_cache_type = io_cache_type_arg;
145 146 147 148 149 150 151 152 153 154
  if (!inited)
  {
    inited=1;
    (void) pthread_mutex_init(&LOCK_log,MY_MUTEX_INIT_SLOW);
    (void) pthread_mutex_init(&LOCK_index, MY_MUTEX_INIT_SLOW);
  }
}

void MYSQL_LOG::close_index()
{
155 156 157 158 159
  if (index_file >= 0)
  {
    my_close(index_file, MYF(0));
    index_file = -1;
  }
160
}
unknown's avatar
unknown committed
161 162 163 164

void MYSQL_LOG::open(const char *log_name, enum_log_type log_type_arg,
		     const char *new_name)
{
165 166
  MY_STAT tmp_stat;
  char buff[512];
167 168
  File file= -1;
  bool do_magic;
169 170
  
  if (!inited && log_type_arg == LOG_BIN && *fn_ext(log_name))
unknown's avatar
unknown committed
171
      no_rotate = 1;
172
  init(log_type_arg);
173 174 175
  
  if (!(name=my_strdup(log_name,MYF(MY_WME))))
    goto err;
unknown's avatar
unknown committed
176 177 178
  if (new_name)
    strmov(log_file_name,new_name);
  else if (generate_new_name(log_file_name, name))
179
    goto err;
unknown's avatar
unknown committed
180 181 182 183 184

  if (log_type == LOG_BIN && !index_file_name[0])
    fn_format(index_file_name, name, mysql_data_home, ".index", 6);
  
  db[0]=0;
185 186
  do_magic = ((log_type == LOG_BIN) && !my_stat(log_file_name,
						&tmp_stat, MYF(0)));
unknown's avatar
unknown committed
187
  
unknown's avatar
unknown committed
188
  if ((file=my_open(log_file_name,O_CREAT | O_APPEND | O_WRONLY | O_BINARY,
189
		    MYF(MY_WME | ME_WAITTANG))) < 0 ||
190
      init_io_cache(&log_file, file, IO_SIZE, io_cache_type,
191 192
		    my_tell(file,MYF(MY_WME)), 0, MYF(MY_WME | MY_NABP)))
    goto err;
unknown's avatar
unknown committed
193 194 195

  if (log_type == LOG_NORMAL)
  {
196
    char *end;
unknown's avatar
unknown committed
197
#ifdef __NT__
198
    sprintf(buff, "%s, Version: %s, started with:\nTCP Port: %d, Named Pipe: %s\n", my_progname, server_version, mysql_port, mysql_unix_port);
unknown's avatar
unknown committed
199
#else
200
    sprintf(buff, "%s, Version: %s, started with:\nTcp port: %d  Unix socket: %s\n", my_progname,server_version,mysql_port,mysql_unix_port);
unknown's avatar
unknown committed
201
#endif
202
    end=strmov(strend(buff),"Time                 Id Command    Argument\n");
unknown's avatar
unknown committed
203
    if (my_b_write(&log_file, (byte*) buff,(uint) (end-buff)) ||
204 205
	flush_io_cache(&log_file))
      goto err;
unknown's avatar
unknown committed
206 207 208 209 210 211
  }
  else if (log_type == LOG_NEW)
  {
    time_t skr=time(NULL);
    struct tm tm_tmp;
    localtime_r(&skr,&tm_tmp);
212
    sprintf(buff,"# %s, Version: %s at %02d%02d%02d %2d:%02d:%02d\n",
unknown's avatar
unknown committed
213 214 215 216 217 218 219
	    my_progname,server_version,
	    tm_tmp.tm_year % 100,
	    tm_tmp.tm_mon+1,
	    tm_tmp.tm_mday,
	    tm_tmp.tm_hour,
	    tm_tmp.tm_min,
	    tm_tmp.tm_sec);
unknown's avatar
unknown committed
220
    if (my_b_write(&log_file, (byte*) buff,(uint) strlen(buff)) ||
221 222
	flush_io_cache(&log_file))
      goto err;
unknown's avatar
unknown committed
223 224 225
  }
  else if (log_type == LOG_BIN)
  {
226
      bool error;
unknown's avatar
unknown committed
227 228 229 230 231 232 233
    /*
      Explanation of the boolean black magic:
      if we are supposed to write magic number try write
      clean up if failed
      then if index_file has not been previously opened, try to open it
      clean up if failed
    */
234
    if ((do_magic && my_b_write(&log_file, (byte*) BINLOG_MAGIC, 4)) ||
235
	open_index(O_APPEND | O_RDWR | O_CREAT))
236
      goto err;
unknown's avatar
unknown committed
237 238

    log_seq = 1;
239 240 241 242 243 244 245
    if (need_start_event)
    {
      Start_log_event s;
      s.set_log_seq(0, this);
      s.write(&log_file);
      need_start_event=0;
    }
unknown's avatar
unknown committed
246
    flush_io_cache(&log_file);
unknown's avatar
unknown committed
247
    pthread_mutex_lock(&LOCK_index);
unknown's avatar
unknown committed
248
    error=(my_write(index_file, (byte*) log_file_name, strlen(log_file_name),
unknown's avatar
unknown committed
249
		    MYF(MY_NABP | MY_WME)) ||
unknown's avatar
unknown committed
250
	   my_write(index_file, (byte*) "\n", 1, MYF(MY_NABP | MY_WME)));
unknown's avatar
unknown committed
251
    pthread_mutex_unlock(&LOCK_index);
unknown's avatar
unknown committed
252 253
    if (error)
    {
254
      close_index();
unknown's avatar
unknown committed
255 256
      goto err;
    }
unknown's avatar
unknown committed
257
  }
258 259 260
  return;

err:
unknown's avatar
unknown committed
261
  sql_print_error("Could not use %s for logging (error %d)", log_name,errno);
262 263 264 265 266 267 268 269
  if (file >= 0)
    my_close(file,MYF(0));
  end_io_cache(&log_file);
  x_free(name); name=0;
  log_type=LOG_CLOSED;

  return;
  
unknown's avatar
unknown committed
270 271 272 273 274
}

int MYSQL_LOG::get_current_log(LOG_INFO* linfo)
{
  pthread_mutex_lock(&LOCK_log);
275 276
  strmake(linfo->log_file_name, log_file_name, sizeof(linfo->log_file_name)-1);
  linfo->pos = my_b_tell(&log_file);
unknown's avatar
unknown committed
277 278 279 280 281 282 283
  pthread_mutex_unlock(&LOCK_log);
  return 0;
}

// if log_name is "" we stop at the first entry
int MYSQL_LOG::find_first_log(LOG_INFO* linfo, const char* log_name)
{
284 285
  if (index_file < 0)
    return LOG_INFO_INVALID;
unknown's avatar
unknown committed
286 287
  int error = 0;
  char* fname = linfo->log_file_name;
unknown's avatar
unknown committed
288
  uint log_name_len = (uint) strlen(log_name);
289
  IO_CACHE io_cache;
unknown's avatar
unknown committed
290

291 292
  // mutex needed because we need to make sure the file pointer does not move
  // from under our feet
unknown's avatar
unknown committed
293
  pthread_mutex_lock(&LOCK_index);
294 295
  if (init_io_cache(&io_cache, index_file, IO_SIZE, READ_CACHE, (my_off_t) 0,
		    0, MYF(MY_WME)))
296 297 298 299 300 301
  {
    error = LOG_INFO_SEEK;
    goto err;
  }
  for(;;)
  {
302
    uint length;
unknown's avatar
unknown committed
303
    if (!(length=my_b_gets(&io_cache, fname, FN_REFLEN-1)))
unknown's avatar
unknown committed
304
    {
305
      error = !io_cache.error ? LOG_INFO_EOF : LOG_INFO_IO;
unknown's avatar
unknown committed
306 307 308
      goto err;
    }

309 310
    // if the log entry matches, empty string matching anything
    if (!log_name_len ||
unknown's avatar
unknown committed
311
	(log_name_len == length-1 && fname[log_name_len] == '\n' &&
312
	 !memcmp(fname, log_name, log_name_len)))
unknown's avatar
unknown committed
313
    {
314 315
      fname[length-1]=0;			// remove last \n
      linfo->index_file_offset = my_b_tell(&io_cache);
316
      break;
unknown's avatar
unknown committed
317
    }
318
  }
unknown's avatar
unknown committed
319
  error = 0;
320

unknown's avatar
unknown committed
321 322
err:
  pthread_mutex_unlock(&LOCK_index);
323
  end_io_cache(&io_cache);
unknown's avatar
unknown committed
324 325 326
  return error;
     
}
unknown's avatar
unknown committed
327

328

unknown's avatar
unknown committed
329 330 331 332
int MYSQL_LOG::find_next_log(LOG_INFO* linfo)
{
  // mutex needed because we need to make sure the file pointer does not move
  // from under our feet
unknown's avatar
unknown committed
333
  if (index_file < 0) return LOG_INFO_INVALID;
unknown's avatar
unknown committed
334 335
  int error = 0;
  char* fname = linfo->log_file_name;
336 337
  IO_CACHE io_cache;
  uint length;
unknown's avatar
unknown committed
338

339 340 341 342 343 344 345 346 347 348 349 350 351 352 353
  pthread_mutex_lock(&LOCK_index);
  if (init_io_cache(&io_cache, index_file, IO_SIZE, 
		    READ_CACHE, (my_off_t) linfo->index_file_offset, 0,
		    MYF(MY_WME)))
  {
    error = LOG_INFO_SEEK;
    goto err;
  }
  if (!(length=my_b_gets(&io_cache, fname, FN_REFLEN)))
  {
    error = !io_cache.error ? LOG_INFO_EOF : LOG_INFO_IO;
    goto err;
  }
  fname[length-1]=0;				// kill /n
  linfo->index_file_offset = my_b_tell(&io_cache);
unknown's avatar
unknown committed
354
  error = 0;
355

unknown's avatar
unknown committed
356 357
err:
  pthread_mutex_unlock(&LOCK_index);
358
  end_io_cache(&io_cache);
unknown's avatar
unknown committed
359 360 361
  return error;
}

unknown's avatar
merge  
unknown committed
362
 
unknown's avatar
unknown committed
363 364
int MYSQL_LOG::purge_logs(THD* thd, const char* to_log)
{
365 366
  if (index_file < 0) return LOG_INFO_INVALID;
  if (no_rotate) return LOG_INFO_PURGE_NO_ROTATE;
unknown's avatar
unknown committed
367 368
  int error;
  char fname[FN_REFLEN];
unknown's avatar
unknown committed
369
  char *p;
unknown's avatar
unknown committed
370 371 372 373
  uint fname_len, i;
  bool logs_to_purge_inited = 0, logs_to_keep_inited = 0, found_log = 0;
  DYNAMIC_ARRAY logs_to_purge, logs_to_keep;
  my_off_t purge_offset ;
unknown's avatar
unknown committed
374
  LINT_INIT(purge_offset);
375
  IO_CACHE io_cache;
unknown's avatar
unknown committed
376
  
unknown's avatar
unknown committed
377 378
  pthread_mutex_lock(&LOCK_index);
  
379 380 381 382 383 384 385 386 387 388 389
  if (init_io_cache(&io_cache,index_file, IO_SIZE*2, READ_CACHE, (my_off_t) 0,
		    0, MYF(MY_WME)))
  {
    error = LOG_INFO_MEM;
    goto err;
  }
  if (init_dynamic_array(&logs_to_purge, sizeof(char*), 1024, 1024))
  {
    error = LOG_INFO_MEM;
    goto err;
  }
unknown's avatar
unknown committed
390 391
  logs_to_purge_inited = 1;
  
392 393 394 395 396
  if (init_dynamic_array(&logs_to_keep, sizeof(char*), 1024, 1024))
  {
    error = LOG_INFO_MEM;
    goto err;
  }
unknown's avatar
unknown committed
397 398 399 400
  logs_to_keep_inited = 1;

  
  for(;;)
401 402 403
  {
    my_off_t init_purge_offset= my_b_tell(&io_cache);
    if (!(fname_len=my_b_gets(&io_cache, fname, FN_REFLEN)))
unknown's avatar
unknown committed
404
    {
405 406 407 408 409 410 411 412 413 414 415 416
      if(!io_cache.error)
	break;
      error = LOG_INFO_IO;
      goto err;
    }

    fname[--fname_len]=0;			// kill \n
    if(!memcmp(fname, to_log, fname_len + 1 ))
    {
      found_log = 1;
      purge_offset = init_purge_offset;
    }
unknown's avatar
unknown committed
417
      
418 419 420 421 422 423
    // if one of the logs before the target is in use
    if(!found_log && log_in_use(fname))
    {
      error = LOG_INFO_IN_USE;
      goto err;
    }
unknown's avatar
unknown committed
424
      
unknown's avatar
unknown committed
425
    if (!(p = sql_memdup(fname, fname_len+1)) ||
426 427
	insert_dynamic(found_log ? &logs_to_keep : &logs_to_purge,
		       (gptr) &p))
unknown's avatar
unknown committed
428
    {
429
      error = LOG_INFO_MEM;
unknown's avatar
unknown committed
430 431
      goto err;
    }
432 433 434 435 436 437 438 439
  }
  
  end_io_cache(&io_cache);
  if(!found_log)
  {
    error = LOG_INFO_EOF;
    goto err;
  }
unknown's avatar
unknown committed
440 441
  
  for(i = 0; i < logs_to_purge.elements; i++)
442 443 444 445 446 447
  {
    char* l;
    get_dynamic(&logs_to_purge, (gptr)&l, i);
    if (my_delete(l, MYF(MY_WME)))
      sql_print_error("Error deleting %s during purge", l);
  }
unknown's avatar
unknown committed
448 449 450 451
  
  // if we get killed -9 here, the sysadmin would have to do a small
  // vi job on the log index file after restart - otherwise, this should
  // be safe
452 453 454
#ifdef HAVE_FTRUNCATE
  if (ftruncate(index_file,0))
  {
unknown's avatar
unknown committed
455
    sql_print_error("Could not truncate the binlog index file \
456 457 458 459 460 461 462 463
during log purge for write");
    error = LOG_INFO_FATAL;
    goto err;
  }
  my_seek(index_file, 0, MY_SEEK_CUR,MYF(MY_WME));
#else
  my_close(index_file, MYF(MY_WME));
  my_delete(index_file_name, MYF(MY_WME));
unknown's avatar
unknown committed
464
  if(!(index_file = my_open(index_file_name,
unknown's avatar
unknown committed
465
			    O_CREAT | O_BINARY | O_RDWR | O_APPEND,
466
			    MYF(MY_WME))))
unknown's avatar
unknown committed
467
  {
unknown's avatar
unknown committed
468
    sql_print_error("Could not re-open the binlog index file \
unknown's avatar
unknown committed
469 470 471 472
during log purge for write");
    error = LOG_INFO_FATAL;
    goto err;
  }
473
#endif
unknown's avatar
unknown committed
474 475
  
  for(i = 0; i < logs_to_keep.elements; i++)
476 477 478
  {
    char* l;
    get_dynamic(&logs_to_keep, (gptr)&l, i);
unknown's avatar
unknown committed
479 480
    if (my_write(index_file, (byte*) l, strlen(l), MYF(MY_WME|MY_NABP)) ||
	my_write(index_file, (byte*) "\n", 1, MYF(MY_WME|MY_NABP)))
unknown's avatar
unknown committed
481
    {
482 483
      error = LOG_INFO_FATAL;
      goto err;
unknown's avatar
unknown committed
484 485
    }
  }
486

unknown's avatar
unknown committed
487 488 489
  // now update offsets
  adjust_linfo_offsets(purge_offset);
  error = 0;
490

unknown's avatar
unknown committed
491 492 493 494 495 496
err:
  pthread_mutex_unlock(&LOCK_index);
  if(logs_to_purge_inited)
    delete_dynamic(&logs_to_purge);
  if(logs_to_keep_inited)
    delete_dynamic(&logs_to_keep);
497
  end_io_cache(&io_cache);
unknown's avatar
unknown committed
498 499 500
  return error;
}

501

unknown's avatar
unknown committed
502 503 504
// we assume that buf has at least FN_REFLEN bytes alloced
void MYSQL_LOG::make_log_name(char* buf, const char* log_ident)
{
505
  buf[0] = 0;					// In case of error
506
  if (inited)
507 508 509 510 511
  {
    int dir_len = dirname_length(log_file_name); 
    int ident_len = (uint) strlen(log_ident);
    if (dir_len + ident_len + 1 > FN_REFLEN)
      return; // protection agains malicious buffer overflow
unknown's avatar
unknown committed
512
      
513 514 515 516
    memcpy(buf, log_file_name, dir_len);
    // copy filename + end null
    memcpy(buf + dir_len, log_ident, ident_len + 1);
  }
unknown's avatar
unknown committed
517 518 519 520 521 522 523
}

bool MYSQL_LOG::is_active(const char* log_file_name)
{
  return inited && !strcmp(log_file_name, this->log_file_name);
}

524
void MYSQL_LOG::new_file(bool inside_mutex)
unknown's avatar
unknown committed
525
{
unknown's avatar
unknown committed
526
  if (is_open())
unknown's avatar
unknown committed
527 528
  {
    char new_name[FN_REFLEN], *old_name=name;
529 530
    if (!inside_mutex)
      VOID(pthread_mutex_lock(&LOCK_log));
unknown's avatar
unknown committed
531 532

    if (!no_rotate)
unknown's avatar
unknown committed
533 534
    {
      /*
unknown's avatar
unknown committed
535 536
	only rotate open logs that are marked non-rotatable
	(binlog with constant name are non-rotatable)
unknown's avatar
unknown committed
537
      */
unknown's avatar
unknown committed
538 539 540 541 542 543 544 545 546 547 548 549
      if (generate_new_name(new_name, name))
      {
	if (!inside_mutex)
	  VOID(pthread_mutex_unlock(&LOCK_log));
	return;					// Something went wrong
      }
      if (log_type == LOG_BIN)
      {
	/*
	  We log the whole file name for log file as the user may decide
	  to change base names at some point.
	*/
unknown's avatar
unknown committed
550 551 552 553 554 555 556 557 558 559 560
	THD* thd = current_thd;
	Rotate_log_event r(thd,new_name+dirname_length(new_name));
	r.set_log_seq(0, this);

	/*
	  This log rotation could have been initiated by a master of
	  the slave running with log-bin we set the flag on rotate
	  event to prevent inifinite log rotation loop
	*/
	if (thd && slave_thd && thd == slave_thd)
	  r.flags |= LOG_EVENT_FORCED_ROTATE_F;
unknown's avatar
unknown committed
561 562 563
	r.write(&log_file);
	VOID(pthread_cond_broadcast(&COND_binlog_update));
      }
unknown's avatar
unknown committed
564 565
      else
	strmov(new_name, old_name);		// Reopen old file name
unknown's avatar
unknown committed
566 567 568 569 570 571 572
    }
    name=0;
    close();
    open(old_name, log_type, new_name);
    my_free(old_name,MYF(0));
    last_time=query_start=0;
    write_error=0;
573 574
    if (!inside_mutex)
      VOID(pthread_mutex_unlock(&LOCK_log));
unknown's avatar
unknown committed
575 576 577 578
  }
}


579
bool MYSQL_LOG::write(THD *thd,enum enum_server_command command,
unknown's avatar
unknown committed
580 581
		      const char *format,...)
{
582
  if (is_open() && (what_to_log & (1L << (uint) command)))
unknown's avatar
unknown committed
583
  {
584
    int error=0;
unknown's avatar
unknown committed
585
    VOID(pthread_mutex_lock(&LOCK_log));
586 587

    /* Test if someone closed after the is_open test */
unknown's avatar
unknown committed
588 589 590 591
    if (log_type != LOG_CLOSED)
    {
      time_t skr;
      ulong id;
592 593 594 595
      va_list args;
      va_start(args,format);
      char buff[32];

unknown's avatar
unknown committed
596 597 598 599 600 601
      if (thd)
      {						// Normal thread
	if ((thd->options & OPTION_LOG_OFF) &&
	    (thd->master_access & PROCESS_ACL))
	{
	  VOID(pthread_mutex_unlock(&LOCK_log));
602
	  return 0;				// No logging
unknown's avatar
unknown committed
603 604 605 606 607 608 609 610 611 612 613 614 615 616 617 618 619
	}
	id=thd->thread_id;
	if (thd->user_time || !(skr=thd->query_start()))
	  skr=time(NULL);			// Connected
      }
      else
      {						// Log from connect handler
	skr=time(NULL);
	id=0;
      }
      if (skr != last_time)
      {
	last_time=skr;
	struct tm tm_tmp;
	struct tm *start;
	localtime_r(&skr,&tm_tmp);
	start=&tm_tmp;
620 621 622 623 624 625 626 627
	/* Note that my_b_write() assumes it knows the length for this */
	sprintf(buff,"%02d%02d%02d %2d:%02d:%02d\t",
		start->tm_year % 100,
		start->tm_mon+1,
		start->tm_mday,
		start->tm_hour,
		start->tm_min,
		start->tm_sec);
unknown's avatar
unknown committed
628
	if (my_b_write(&log_file, (byte*) buff,16))
unknown's avatar
unknown committed
629 630
	  error=errno;
      }
unknown's avatar
unknown committed
631
      else if (my_b_write(&log_file, (byte*) "\t\t",2) < 0)
unknown's avatar
unknown committed
632
	error=errno;
633
      sprintf(buff,"%7ld %-11.11s", id,command_name[(uint) command]);
unknown's avatar
unknown committed
634
      if (my_b_write(&log_file, (byte*) buff,strlen(buff)))
unknown's avatar
unknown committed
635 636 637
	error=errno;
      if (format)
      {
unknown's avatar
unknown committed
638
	if (my_b_write(&log_file, (byte*) " ",1) ||
639
	    my_b_vprintf(&log_file,format,args) == (uint) -1)
unknown's avatar
unknown committed
640 641
	  error=errno;
      }
unknown's avatar
unknown committed
642
      if (my_b_write(&log_file, (byte*) "\n",1) ||
643
	  flush_io_cache(&log_file))
unknown's avatar
unknown committed
644 645 646 647 648 649
	error=errno;
      if (error && ! write_error)
      {
	write_error=1;
	sql_print_error(ER(ER_ERROR_ON_WRITE),name,error);
      }
650
      va_end(args);
unknown's avatar
unknown committed
651 652
    }
    VOID(pthread_mutex_unlock(&LOCK_log));
653
    return error != 0;
unknown's avatar
unknown committed
654
  }
655
  return 0;
unknown's avatar
unknown committed
656 657 658
}


659
bool MYSQL_LOG::write(Log_event* event_info)
unknown's avatar
unknown committed
660
{
661
  /* In most cases this is only called if 'is_open()' is true */
unknown's avatar
unknown committed
662
  bool error=0;
663 664
  bool should_rotate = 0;
  
unknown's avatar
unknown committed
665 666
  if (!inited)					// Can't use mutex if not init
    return 0;
667
  VOID(pthread_mutex_lock(&LOCK_log));
668
  if (is_open())
unknown's avatar
unknown committed
669
  {
670
    THD *thd=event_info->thd;
671
    const char* db = event_info->get_db();
unknown's avatar
unknown committed
672
#ifdef USING_TRANSACTIONS    
unknown's avatar
unknown committed
673
    IO_CACHE *file = ((event_info->get_cache_stmt() && thd) ?
674
		      &thd->transaction.trans_log :
675
		      &log_file);
unknown's avatar
unknown committed
676 677 678
#else
    IO_CACHE *file = &log_file;
#endif    
679
    if ((thd && !(thd->options & OPTION_BIN_LOG) &&
680
	 (thd->master_access & PROCESS_ACL)) ||
681
	(db && !db_ok(db, binlog_do_db, binlog_ignore_db)))
unknown's avatar
unknown committed
682
    {
683 684 685
      VOID(pthread_mutex_unlock(&LOCK_log));
      return 0;
    }
unknown's avatar
unknown committed
686 687
    error=1;

688
    if (thd && thd->last_insert_id_used)
689
    {
690
      Intvar_log_event e(thd,(uchar)LAST_INSERT_ID_EVENT,thd->last_insert_id);
unknown's avatar
unknown committed
691
      e.set_log_seq(thd, this);
unknown's avatar
unknown committed
692
      if (thd->server_id)
unknown's avatar
merge  
unknown committed
693
        e.server_id = thd->server_id;
694 695 696
      if (e.write(file))
	goto err;
    }
697
    if (thd && thd->insert_id_used)
698
    {
699
      Intvar_log_event e(thd,(uchar)INSERT_ID_EVENT,thd->last_insert_id);
unknown's avatar
unknown committed
700
      e.set_log_seq(thd, this);
unknown's avatar
unknown committed
701 702
      if (thd->server_id)
        e.server_id = thd->server_id;
703 704 705
      if (e.write(file))
	goto err;
    }
706
    if (thd && thd->convert_set)
707 708 709 710 711 712 713 714
    {
      char buf[1024] = "SET CHARACTER SET ";
      char* p = strend(buf);
      p = strmov(p, thd->convert_set->name);
      int save_query_length = thd->query_length;
      // just in case somebody wants it later
      thd->query_length = (uint)(p - buf);
      Query_log_event e(thd, buf);
unknown's avatar
unknown committed
715
      e.set_log_seq(thd, this);
716 717 718 719
      if (e.write(file))
	goto err;
      thd->query_length = save_query_length; // clean up
    }
unknown's avatar
unknown committed
720
    event_info->set_log_seq(thd, this);
721 722 723 724
    if (event_info->write(file) ||
	file == &log_file && flush_io_cache(file))
      goto err;
    error=0;
725 726
    should_rotate = (file == &log_file &&
		     (uint)my_b_tell(file) >= max_binlog_size); 
727 728 729 730 731 732 733 734 735 736 737 738
err:
    if (error)
    {
      if (my_errno == EFBIG)
	my_error(ER_TRANS_CACHE_FULL, MYF(0));
      else
	my_error(ER_ERROR_ON_WRITE, MYF(0), name, errno);
      write_error=1;
    }
    if (file == &log_file)
      VOID(pthread_cond_broadcast(&COND_binlog_update));
  }
739
  if (should_rotate)
740 741
    new_file(1); // inside mutex
  VOID(pthread_mutex_unlock(&LOCK_log));
742 743 744
  return error;
}

unknown's avatar
unknown committed
745 746 747 748 749 750 751 752 753
uint MYSQL_LOG::next_file_id()
{
  uint res;
  pthread_mutex_lock(&LOCK_log);
  res = file_id++;
  pthread_mutex_unlock(&LOCK_log);
  return res;
}

754 755 756 757 758 759 760 761 762 763
/*
  Write a cached log entry to the binary log
  We only come here if there is something in the cache.
  'cache' needs to be reinitialized after this functions returns.
*/

bool MYSQL_LOG::write(IO_CACHE *cache)
{
  VOID(pthread_mutex_lock(&LOCK_log));
  bool error=1;
764
  
765 766 767 768
  if (is_open())
  {
    uint length;

unknown's avatar
unknown committed
769
    if (reinit_io_cache(cache, READ_CACHE, 0, 0, 0))
770
    {
unknown's avatar
unknown committed
771
      sql_print_error(ER(ER_ERROR_ON_WRITE), cache->file_name, errno);
772 773
      goto err;
    }
774 775
    length=my_b_bytes_in_cache(cache);
    do
776 777
    {
      if (my_b_write(&log_file, cache->rc_pos, length))
778
      {
779
	if (!write_error)
780
	  sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
781
	goto err;
782
      }
783
      cache->rc_pos=cache->rc_end;		// Mark buffer used up
784
    } while ((length=my_b_fill(cache)));
785 786 787
    if (flush_io_cache(&log_file))
    {
      if (!write_error)
unknown's avatar
unknown committed
788
	sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
789 790 791 792
      goto err;
    }
    if (cache->error)				// Error on read
    {
unknown's avatar
unknown committed
793
      sql_print_error(ER(ER_ERROR_ON_READ), cache->file_name, errno);
794
      goto err;
unknown's avatar
unknown committed
795 796
    }
  }
797 798 799 800 801 802 803 804
  error=0;

err:
  if (error)
    write_error=1;
  else
    VOID(pthread_cond_broadcast(&COND_binlog_update));
    
805 806
  VOID(pthread_mutex_unlock(&LOCK_log));
  
807
  return error;
unknown's avatar
unknown committed
808 809
}

810

unknown's avatar
unknown committed
811 812
/* Write update log in a format suitable for incremental backup */

813
bool MYSQL_LOG::write(THD *thd,const char *query, uint query_length,
814
		      time_t query_start)
unknown's avatar
unknown committed
815
{
816
  bool error=0;
817
  if (is_open())
unknown's avatar
unknown committed
818
  {
819
    time_t current_time;
unknown's avatar
unknown committed
820
    VOID(pthread_mutex_lock(&LOCK_log));
821
    if (is_open())
unknown's avatar
unknown committed
822
    {						// Safety agains reopen
823
      int tmp_errno=0;
unknown's avatar
unknown committed
824 825 826 827 828 829
      char buff[80],*end;
      end=buff;
      if (!(thd->options & OPTION_UPDATE_LOG) &&
	  (thd->master_access & PROCESS_ACL))
      {
	VOID(pthread_mutex_unlock(&LOCK_log));
830
	return 0;
unknown's avatar
unknown committed
831
      }
unknown's avatar
unknown committed
832
      if ((specialflag & SPECIAL_LONG_LOG_FORMAT) || query_start)
unknown's avatar
unknown committed
833
      {
834 835
	current_time=time(NULL);
	if (current_time != last_time)
unknown's avatar
unknown committed
836
	{
837
	  last_time=current_time;
unknown's avatar
unknown committed
838 839
	  struct tm tm_tmp;
	  struct tm *start;
840
	  localtime_r(&current_time,&tm_tmp);
unknown's avatar
unknown committed
841
	  start=&tm_tmp;
842 843 844 845 846 847 848 849
	  /* Note that my_b_write() assumes it knows the length for this */
	  sprintf(buff,"# Time: %02d%02d%02d %2d:%02d:%02d\n",
		  start->tm_year % 100,
		  start->tm_mon+1,
		  start->tm_mday,
		  start->tm_hour,
		  start->tm_min,
		  start->tm_sec);
unknown's avatar
unknown committed
850
	  if (my_b_write(&log_file, (byte*) buff,24))
851
	    tmp_errno=errno;
unknown's avatar
unknown committed
852
	}
unknown's avatar
unknown committed
853
	if (my_b_printf(&log_file, "# User@Host: %s[%s] @ %s [%s]\n",
854 855 856
			thd->priv_user,
			thd->user,
			thd->host ? thd->host : "",
unknown's avatar
unknown committed
857
			thd->ip ? thd->ip : "") == (uint) -1)
858
	  tmp_errno=errno;
unknown's avatar
unknown committed
859
      }
860 861 862
      if (query_start)
      {
	/* For slow query log */
863
	if (my_b_printf(&log_file,
864
			"# Query_time: %lu  Lock_time: %lu  Rows_sent: %lu  Rows_examined: %lu\n",
865 866
			(ulong) (current_time - query_start),
			(ulong) (thd->time_after_lock - query_start),
867 868 869
			(ulong) thd->sent_row_count,
			(ulong) thd->examined_row_count) == (uint) -1)
	  tmp_errno=errno;
870
      }
unknown's avatar
unknown committed
871 872
      if (thd->db && strcmp(thd->db,db))
      {						// Database changed
unknown's avatar
unknown committed
873
	if (my_b_printf(&log_file,"use %s;\n",thd->db) == (uint) -1)
874
	  tmp_errno=errno;
unknown's avatar
unknown committed
875 876 877 878 879 880 881 882 883 884 885 886 887 888 889 890 891 892 893 894 895 896 897 898 899 900 901 902 903 904
	strmov(db,thd->db);
      }
      if (thd->last_insert_id_used)
      {
	end=strmov(end,",last_insert_id=");
	end=longlong10_to_str((longlong) thd->current_insert_id,end,-10);
      }
      // Save value if we do an insert.
      if (thd->insert_id_used)
      {
	if (specialflag & SPECIAL_LONG_LOG_FORMAT)
	{
	  end=strmov(end,",insert_id=");
	  end=longlong10_to_str((longlong) thd->last_insert_id,end,-10);
	}
      }
      if (thd->query_start_used)
      {
	if (query_start != thd->query_start())
	{
	  query_start=thd->query_start();
	  end=strmov(end,",timestamp=");
	  end=int10_to_str((long) query_start,end,10);
	}
      }
      if (end != buff)
      {
	*end++=';';
	*end++='\n';
	*end=0;
unknown's avatar
unknown committed
905 906
	if (my_b_write(&log_file, (byte*) "SET ",4) ||
	    my_b_write(&log_file, (byte*) buff+1,(uint) (end-buff)-1))
907
	  tmp_errno=errno;
unknown's avatar
unknown committed
908 909 910 911 912 913
      }
      if (!query)
      {
	query="#adminstrator command";
	query_length=21;
      }
unknown's avatar
unknown committed
914 915
      if (my_b_write(&log_file, (byte*) query,query_length) ||
	  my_b_write(&log_file, (byte*) ";\n",2) ||
916
	  flush_io_cache(&log_file))
917 918
	tmp_errno=errno;
      if (tmp_errno)
unknown's avatar
unknown committed
919
      {
920 921 922 923 924 925
	error=1;
	if (! write_error)
	{
	  write_error=1;
	  sql_print_error(ER(ER_ERROR_ON_WRITE),name,error);
	}
unknown's avatar
unknown committed
926 927 928 929
      }
    }
    VOID(pthread_mutex_unlock(&LOCK_log));
  }
930
  return error;
unknown's avatar
unknown committed
931 932 933 934 935
}


void MYSQL_LOG::close(bool exiting)
{					// One can't set log_type here!
936
  if (is_open())
unknown's avatar
unknown committed
937
  {
938
    File file=log_file.file;
unknown's avatar
unknown committed
939 940 941
    if (log_type == LOG_BIN)
    {
      Stop_log_event s;
unknown's avatar
unknown committed
942
      s.set_log_seq(0, this);
943
      s.write(&log_file);
unknown's avatar
unknown committed
944 945
      VOID(pthread_cond_broadcast(&COND_binlog_update));
    }
946 947
    end_io_cache(&log_file);
    if (my_close(file,MYF(0)) < 0 && ! write_error)
unknown's avatar
unknown committed
948 949 950 951 952
    {
      write_error=1;
      sql_print_error(ER(ER_ERROR_ON_WRITE),name,errno);
    }
  }
953
  if (exiting && index_file >= 0)
954
  {
955
    if (my_close(index_file,MYF(0)) < 0 && ! write_error)
unknown's avatar
unknown committed
956
    {
957 958
      write_error=1;
      sql_print_error(ER(ER_ERROR_ON_WRITE),name,errno);
unknown's avatar
unknown committed
959
    }
unknown's avatar
unknown committed
960 961
    index_file=-1;
    log_type=LOG_CLOSED;
962
  }
963
  safeFree(name);
unknown's avatar
unknown committed
964 965 966 967 968 969 970 971 972 973 974 975 976 977 978 979 980 981 982 983 984 985 986 987 988 989 990 991 992 993 994 995 996 997 998 999 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014
}


	/* Check if a string is a valid number */
	/* Output: TRUE -> number */

static bool test_if_number(register const char *str,
			   long *res, bool allow_wildcards)
{
  reg2 int flag;
  const char *start;
  DBUG_ENTER("test_if_number");

  flag=0; start=str;
  while (*str++ == ' ') ;
  if (*--str == '-' || *str == '+')
    str++;
  while (isdigit(*str) || (allow_wildcards &&
			   (*str == wild_many || *str == wild_one)))
  {
    flag=1;
    str++;
  }
  if (*str == '.')
  {
    for (str++ ;
	 isdigit(*str) ||
	   (allow_wildcards && (*str == wild_many || *str == wild_one)) ;
	 str++, flag=1) ;
  }
  if (*str != 0 || flag == 0)
    DBUG_RETURN(0);
  if (res)
    *res=atol(start);
  DBUG_RETURN(1);			/* Number ok */
} /* test_if_number */


void sql_print_error(const char *format,...)
{
  va_list args;
  time_t skr;
  struct tm tm_tmp;
  struct tm *start;
  va_start(args,format);
  DBUG_ENTER("sql_print_error");

  VOID(pthread_mutex_lock(&LOCK_error_log));
#ifndef DBUG_OFF
  {
    char buff[1024];
1015
    my_vsnprintf(buff,sizeof(buff)-1,format,args);
unknown's avatar
unknown committed
1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 1030 1031 1032 1033 1034 1035 1036 1037 1038 1039 1040 1041 1042 1043 1044 1045 1046 1047
    DBUG_PRINT("error",("%s",buff));
  }
#endif
  skr=time(NULL);
  localtime_r(&skr,&tm_tmp);
  start=&tm_tmp;
  fprintf(stderr,"%02d%02d%02d %2d:%02d:%02d  ",
	  start->tm_year % 100,
	  start->tm_mon+1,
	  start->tm_mday,
	  start->tm_hour,
	  start->tm_min,
	  start->tm_sec);
  (void) vfprintf(stderr,format,args);
  (void) fputc('\n',stderr);
  fflush(stderr);
  va_end(args);

  VOID(pthread_mutex_unlock(&LOCK_error_log));
  DBUG_VOID_RETURN;
}



void sql_perror(const char *message)
{
#ifdef HAVE_STRERROR
  sql_print_error("%s: %s",message, strerror(errno));
#else
  perror(message);
#endif
}