log.cc 25.4 KB
Newer Older
bk@work.mysql.com's avatar
bk@work.mysql.com 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 */
bk@work.mysql.com's avatar
bk@work.mysql.com committed
20

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

bk@work.mysql.com's avatar
bk@work.mysql.com committed
25 26
#include "mysql_priv.h"
#include "sql_acl.h"
27
#include "sql_repl.h"
bk@work.mysql.com's avatar
bk@work.mysql.com 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;
bk@work.mysql.com's avatar
bk@work.mysql.com 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='.';
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
59
  length= (uint) (end-start+1);
bk@work.mysql.com's avatar
bk@work.mysql.com 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);
}

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
			inited(0), log_seq(1), file_id(1),no_rotate(0)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
85 86 87 88 89
{
  /*
    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'.
  */
90 91
  index_file_name[0] = 0;
  bzero((char*) &log_file,sizeof(log_file));
bk@work.mysql.com's avatar
bk@work.mysql.com committed
92 93 94 95 96
}

MYSQL_LOG::~MYSQL_LOG()
{
  if (inited)
97 98 99 100
  {
    (void) pthread_mutex_destroy(&LOCK_log);
    (void) pthread_mutex_destroy(&LOCK_index);
  }
bk@work.mysql.com's avatar
bk@work.mysql.com committed
101 102 103 104 105
}

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

112

bk@work.mysql.com's avatar
bk@work.mysql.com committed
113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131
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;
}

132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157
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);
}

void MYSQL_LOG::init(enum_log_type log_type_arg)
{
  log_type = log_type_arg;
  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()
{
  if(index_file >= 0)
    {
      my_close(index_file, MYF(0));
      index_file = -1;
    }
}
bk@work.mysql.com's avatar
bk@work.mysql.com committed
158 159 160 161

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

  if (log_type == LOG_BIN && !index_file_name[0])
    fn_format(index_file_name, name, mysql_data_home, ".index", 6);
  
  db[0]=0;
182 183
  do_magic = ((log_type == LOG_BIN) && !my_stat(log_file_name,
						&tmp_stat, MYF(0)));
sasha@mysql.sashanet.com's avatar
sasha@mysql.sashanet.com committed
184
  
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
185
  if ((file=my_open(log_file_name,O_CREAT | O_APPEND | O_WRONLY | O_BINARY,
186 187 188 189
		    MYF(MY_WME | ME_WAITTANG))) < 0 ||
      init_io_cache(&log_file, file, IO_SIZE, WRITE_CACHE,
		    my_tell(file,MYF(MY_WME)), 0, MYF(MY_WME | MY_NABP)))
    goto err;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
190 191 192

  if (log_type == LOG_NORMAL)
  {
193
    char *end;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
194
#ifdef __NT__
195
    sprintf(buff, "%s, Version: %s, started with:\nTCP Port: %d, Named Pipe: %s\n", my_progname, server_version, mysql_port, mysql_unix_port);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
196
#else
197
    sprintf(buff, "%s, Version: %s, started with:\nTcp port: %d  Unix socket: %s\n", my_progname,server_version,mysql_port,mysql_unix_port);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
198
#endif
199
    end=strmov(strend(buff),"Time                 Id Command    Argument\n");
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
200
    if (my_b_write(&log_file, (byte*) buff,(uint) (end-buff)) ||
201 202
	flush_io_cache(&log_file))
      goto err;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
203 204 205 206 207 208
  }
  else if (log_type == LOG_NEW)
  {
    time_t skr=time(NULL);
    struct tm tm_tmp;
    localtime_r(&skr,&tm_tmp);
209
    sprintf(buff,"# %s, Version: %s at %02d%02d%02d %2d:%02d:%02d\n",
bk@work.mysql.com's avatar
bk@work.mysql.com committed
210 211 212 213 214 215 216
	    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);
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
217
    if (my_b_write(&log_file, (byte*) buff,(uint) strlen(buff)) ||
218 219
	flush_io_cache(&log_file))
      goto err;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
220 221 222
  }
  else if (log_type == LOG_BIN)
  {
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
223 224 225 226 227 228 229
    /*
      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
    */
230
    if ((do_magic && my_b_write(&log_file, (byte*) BINLOG_MAGIC, 4)) ||
231
	open_index(O_APPEND | O_RDWR | O_CREAT))
232
      goto err;
233 234

    log_seq = 1;
sasha@mysql.sashanet.com's avatar
sasha@mysql.sashanet.com committed
235
    Start_log_event s;
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
236
    bool error;
237
    s.set_log_seq(0, this);
238
    s.write(&log_file);
239
    flush_io_cache(&log_file);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
240
    pthread_mutex_lock(&LOCK_index);
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
241
    error=(my_write(index_file, (byte*) log_file_name, strlen(log_file_name),
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
242
		    MYF(MY_NABP | MY_WME)) ||
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
243
	   my_write(index_file, (byte*) "\n", 1, MYF(MY_NABP | MY_WME)));
bk@work.mysql.com's avatar
bk@work.mysql.com committed
244
    pthread_mutex_unlock(&LOCK_index);
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
245 246
    if (error)
    {
247
      close_index();
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
248 249
      goto err;
    }
bk@work.mysql.com's avatar
bk@work.mysql.com committed
250
  }
251 252 253
  return;

err:
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
254
  sql_print_error("Could not use %s for logging (error %d)", log_name,errno);
255 256 257 258 259 260 261 262
  if (file >= 0)
    my_close(file,MYF(0));
  end_io_cache(&log_file);
  x_free(name); name=0;
  log_type=LOG_CLOSED;

  return;
  
bk@work.mysql.com's avatar
bk@work.mysql.com committed
263 264 265 266 267
}

int MYSQL_LOG::get_current_log(LOG_INFO* linfo)
{
  pthread_mutex_lock(&LOCK_log);
268 269
  strmake(linfo->log_file_name, log_file_name, sizeof(linfo->log_file_name)-1);
  linfo->pos = my_b_tell(&log_file);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
270 271 272 273 274 275 276
  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)
{
277 278
  if (index_file < 0)
    return LOG_INFO_INVALID;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
279 280
  int error = 0;
  char* fname = linfo->log_file_name;
281
  uint log_name_len = (uint) strlen(log_name);
282
  IO_CACHE io_cache;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
283

284 285
  // mutex needed because we need to make sure the file pointer does not move
  // from under our feet
bk@work.mysql.com's avatar
bk@work.mysql.com committed
286
  pthread_mutex_lock(&LOCK_index);
287 288
  if (init_io_cache(&io_cache, index_file, IO_SIZE, READ_CACHE, (my_off_t) 0,
		    0, MYF(MY_WME)))
289 290 291 292 293 294
  {
    error = LOG_INFO_SEEK;
    goto err;
  }
  for(;;)
  {
295
    uint length;
296
    if (!(length=my_b_gets(&io_cache, fname, FN_REFLEN-1)))
bk@work.mysql.com's avatar
bk@work.mysql.com committed
297
    {
298
      error = !io_cache.error ? LOG_INFO_EOF : LOG_INFO_IO;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
299 300 301
      goto err;
    }

302 303
    // if the log entry matches, empty string matching anything
    if (!log_name_len ||
sasha@mysql.sashanet.com's avatar
sasha@mysql.sashanet.com committed
304
	(log_name_len == length-1 && fname[log_name_len] == '\n' &&
305
	 !memcmp(fname, log_name, log_name_len)))
bk@work.mysql.com's avatar
bk@work.mysql.com committed
306
    {
307 308
      fname[length-1]=0;			// remove last \n
      linfo->index_file_offset = my_b_tell(&io_cache);
309
      break;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
310
    }
311
  }
bk@work.mysql.com's avatar
bk@work.mysql.com committed
312
  error = 0;
313

bk@work.mysql.com's avatar
bk@work.mysql.com committed
314 315
err:
  pthread_mutex_unlock(&LOCK_index);
316
  end_io_cache(&io_cache);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
317 318 319
  return error;
     
}
320

321

bk@work.mysql.com's avatar
bk@work.mysql.com committed
322 323 324 325
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
326
  if (index_file < 0) return LOG_INFO_INVALID;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
327 328
  int error = 0;
  char* fname = linfo->log_file_name;
329 330
  IO_CACHE io_cache;
  uint length;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
331

332 333 334 335 336 337 338 339 340 341 342 343 344 345 346
  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);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
347
  error = 0;
348

bk@work.mysql.com's avatar
bk@work.mysql.com committed
349 350
err:
  pthread_mutex_unlock(&LOCK_index);
351
  end_io_cache(&io_cache);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
352 353 354
  return error;
}

monty@narttu.mysql.fi's avatar
merge  
monty@narttu.mysql.fi committed
355
 
356 357
int MYSQL_LOG::purge_logs(THD* thd, const char* to_log)
{
358 359
  if (index_file < 0) return LOG_INFO_INVALID;
  if (no_rotate) return LOG_INFO_PURGE_NO_ROTATE;
360 361
  int error;
  char fname[FN_REFLEN];
362
  char *p;
363 364 365 366
  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 ;
sasha@laptop.slkc.uswest.net's avatar
sasha@laptop.slkc.uswest.net committed
367
  LINT_INIT(purge_offset);
368
  IO_CACHE io_cache;
369
  
370 371
  pthread_mutex_lock(&LOCK_index);
  
372 373 374 375 376 377 378 379 380 381 382
  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;
  }
383 384
  logs_to_purge_inited = 1;
  
385 386 387 388 389
  if (init_dynamic_array(&logs_to_keep, sizeof(char*), 1024, 1024))
  {
    error = LOG_INFO_MEM;
    goto err;
  }
390 391 392 393
  logs_to_keep_inited = 1;

  
  for(;;)
394 395 396
  {
    my_off_t init_purge_offset= my_b_tell(&io_cache);
    if (!(fname_len=my_b_gets(&io_cache, fname, FN_REFLEN)))
397
    {
398 399 400 401 402 403 404 405 406 407 408 409
      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;
    }
410
      
411 412 413 414 415 416
    // 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;
    }
417
      
418
    if (!(p = sql_memdup(fname, fname_len+1)) ||
419 420
	insert_dynamic(found_log ? &logs_to_keep : &logs_to_purge,
		       (gptr) &p))
421
    {
422
      error = LOG_INFO_MEM;
423 424
      goto err;
    }
425 426 427 428 429 430 431 432
  }
  
  end_io_cache(&io_cache);
  if(!found_log)
  {
    error = LOG_INFO_EOF;
    goto err;
  }
433 434
  
  for(i = 0; i < logs_to_purge.elements; i++)
435 436 437 438 439 440
  {
    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);
  }
441 442 443 444
  
  // 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
445 446 447
#ifdef HAVE_FTRUNCATE
  if (ftruncate(index_file,0))
  {
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
448
    sql_print_error("Could not truncate the binlog index file \
449 450 451 452 453 454 455 456
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));
457
  if(!(index_file = my_open(index_file_name,
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
458
			    O_CREAT | O_BINARY | O_RDWR | O_APPEND,
459
			    MYF(MY_WME))))
460
  {
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
461
    sql_print_error("Could not re-open the binlog index file \
462 463 464 465
during log purge for write");
    error = LOG_INFO_FATAL;
    goto err;
  }
466
#endif
467 468
  
  for(i = 0; i < logs_to_keep.elements; i++)
469 470 471
  {
    char* l;
    get_dynamic(&logs_to_keep, (gptr)&l, i);
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
472 473
    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)))
474
    {
475 476
      error = LOG_INFO_FATAL;
      goto err;
477 478
    }
  }
479

480 481 482
  // now update offsets
  adjust_linfo_offsets(purge_offset);
  error = 0;
483

484 485 486 487 488 489
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);
490
  end_io_cache(&io_cache);
491 492 493
  return error;
}

494

bk@work.mysql.com's avatar
bk@work.mysql.com committed
495 496 497
// we assume that buf has at least FN_REFLEN bytes alloced
void MYSQL_LOG::make_log_name(char* buf, const char* log_ident)
{
498
  buf[0] = 0;					// In case of error
499
  if (inited)
500 501 502 503 504
  {
    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
bk@work.mysql.com's avatar
bk@work.mysql.com committed
505
      
506 507 508 509
    memcpy(buf, log_file_name, dir_len);
    // copy filename + end null
    memcpy(buf + dir_len, log_ident, ident_len + 1);
  }
bk@work.mysql.com's avatar
bk@work.mysql.com committed
510 511 512 513 514 515 516
}

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

517
void MYSQL_LOG::new_file(bool inside_mutex)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
518
{
519 520 521
  // only rotate open logs that are marked non-rotatable
  // (binlog with constant name are non-rotatable)
  if (is_open() && ! no_rotate)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
522 523
  {
    char new_name[FN_REFLEN], *old_name=name;
524 525
    if (!inside_mutex)
      VOID(pthread_mutex_lock(&LOCK_log));
bk@work.mysql.com's avatar
bk@work.mysql.com committed
526
    if (generate_new_name(new_name, name))
527
    {
528 529
      if (!inside_mutex)
        VOID(pthread_mutex_unlock(&LOCK_log));
bk@work.mysql.com's avatar
bk@work.mysql.com committed
530
      return;					// Something went wrong
531
    }
bk@work.mysql.com's avatar
bk@work.mysql.com committed
532 533 534 535 536 537
    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.
      */
538
      THD* thd = current_thd;
539
      Rotate_log_event r(thd,new_name+dirname_length(new_name));
540
      r.set_log_seq(0, this);
541 542 543 544 545 546
      // 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;
547
      r.write(&log_file);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
548 549 550 551 552 553 554 555
      VOID(pthread_cond_broadcast(&COND_binlog_update));
    }
    name=0;
    close();
    open(old_name, log_type, new_name);
    my_free(old_name,MYF(0));
    last_time=query_start=0;
    write_error=0;
556 557
    if (!inside_mutex)
      VOID(pthread_mutex_unlock(&LOCK_log));
bk@work.mysql.com's avatar
bk@work.mysql.com committed
558 559 560 561
  }
}


562
bool MYSQL_LOG::write(THD *thd,enum enum_server_command command,
bk@work.mysql.com's avatar
bk@work.mysql.com committed
563 564
		      const char *format,...)
{
565
  if (is_open() && (what_to_log & (1L << (uint) command)))
bk@work.mysql.com's avatar
bk@work.mysql.com committed
566
  {
567
    int error=0;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
568
    VOID(pthread_mutex_lock(&LOCK_log));
569 570

    /* Test if someone closed after the is_open test */
bk@work.mysql.com's avatar
bk@work.mysql.com committed
571 572 573 574
    if (log_type != LOG_CLOSED)
    {
      time_t skr;
      ulong id;
575 576 577 578
      va_list args;
      va_start(args,format);
      char buff[32];

bk@work.mysql.com's avatar
bk@work.mysql.com committed
579 580 581 582 583 584
      if (thd)
      {						// Normal thread
	if ((thd->options & OPTION_LOG_OFF) &&
	    (thd->master_access & PROCESS_ACL))
	{
	  VOID(pthread_mutex_unlock(&LOCK_log));
585
	  return 0;				// No logging
bk@work.mysql.com's avatar
bk@work.mysql.com committed
586 587 588 589 590 591 592 593 594 595 596 597 598 599 600 601 602
	}
	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;
603 604 605 606 607 608 609 610
	/* 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);
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
611
	if (my_b_write(&log_file, (byte*) buff,16))
bk@work.mysql.com's avatar
bk@work.mysql.com committed
612 613
	  error=errno;
      }
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
614
      else if (my_b_write(&log_file, (byte*) "\t\t",2) < 0)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
615
	error=errno;
616
      sprintf(buff,"%7ld %-11.11s", id,command_name[(uint) command]);
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
617
      if (my_b_write(&log_file, (byte*) buff,strlen(buff)))
bk@work.mysql.com's avatar
bk@work.mysql.com committed
618 619 620
	error=errno;
      if (format)
      {
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
621
	if (my_b_write(&log_file, (byte*) " ",1) ||
622
	    my_b_vprintf(&log_file,format,args) == (uint) -1)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
623 624
	  error=errno;
      }
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
625
      if (my_b_write(&log_file, (byte*) "\n",1) ||
626
	  flush_io_cache(&log_file))
bk@work.mysql.com's avatar
bk@work.mysql.com committed
627 628 629 630 631 632
	error=errno;
      if (error && ! write_error)
      {
	write_error=1;
	sql_print_error(ER(ER_ERROR_ON_WRITE),name,error);
      }
633
      va_end(args);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
634 635
    }
    VOID(pthread_mutex_unlock(&LOCK_log));
636
    return error != 0;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
637
  }
638
  return 0;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
639 640 641
}


642
bool MYSQL_LOG::write(Log_event* event_info)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
643
{
644
  /* In most cases this is only called if 'is_open()' is true */
645
  bool error=0;
646 647
  bool should_rotate = 0;
  
648 649
  if (!inited)					// Can't use mutex if not init
    return 0;
650
  VOID(pthread_mutex_lock(&LOCK_log));
651
  if (is_open())
bk@work.mysql.com's avatar
bk@work.mysql.com committed
652
  {
653
    THD *thd=event_info->thd;
654
    const char* db = event_info->get_db();
655
#ifdef USING_TRANSACTIONS    
sasha@mysql.sashanet.com's avatar
sasha@mysql.sashanet.com committed
656
    IO_CACHE *file = ((event_info->get_cache_stmt() && thd) ?
657
		      &thd->transaction.trans_log :
658
		      &log_file);
659 660 661
#else
    IO_CACHE *file = &log_file;
#endif    
662
    if ((thd && !(thd->options & OPTION_BIN_LOG) &&
663
	 (thd->master_access & PROCESS_ACL)) ||
664
	(db && !db_ok(db, binlog_do_db, binlog_ignore_db)))
bk@work.mysql.com's avatar
bk@work.mysql.com committed
665
    {
666 667 668
      VOID(pthread_mutex_unlock(&LOCK_log));
      return 0;
    }
669 670
    error=1;

671
    if (thd && thd->last_insert_id_used)
672
    {
673
      Intvar_log_event e(thd,(uchar)LAST_INSERT_ID_EVENT,thd->last_insert_id);
674
      e.set_log_seq(thd, this);
675
      if (thd->server_id)
sasha@mysql.sashanet.com's avatar
merge  
sasha@mysql.sashanet.com committed
676
        e.server_id = thd->server_id;
677 678 679
      if (e.write(file))
	goto err;
    }
680
    if (thd && thd->insert_id_used)
681
    {
682
      Intvar_log_event e(thd,(uchar)INSERT_ID_EVENT,thd->last_insert_id);
683
      e.set_log_seq(thd, this);
684 685
      if (thd->server_id)
        e.server_id = thd->server_id;
686 687 688
      if (e.write(file))
	goto err;
    }
689
    if (thd && thd->convert_set)
690 691 692 693 694 695 696 697
    {
      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);
698
      e.set_log_seq(thd, this);
699 700 701 702
      if (e.write(file))
	goto err;
      thd->query_length = save_query_length; // clean up
    }
703
    event_info->set_log_seq(thd, this);
704 705 706 707
    if (event_info->write(file) ||
	file == &log_file && flush_io_cache(file))
      goto err;
    error=0;
708
    should_rotate = (file == &log_file && my_b_tell(file) >= max_binlog_size); 
709 710 711 712 713 714 715 716 717 718 719 720
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));
  }
721
  if (should_rotate)
722 723
    new_file(1); // inside mutex
  VOID(pthread_mutex_unlock(&LOCK_log));
724 725 726
  return error;
}

727 728 729 730 731 732 733 734 735
uint MYSQL_LOG::next_file_id()
{
  uint res;
  pthread_mutex_lock(&LOCK_log);
  res = file_id++;
  pthread_mutex_unlock(&LOCK_log);
  return res;
}

736 737 738 739 740 741 742 743 744 745
/*
  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;
746
  
747 748 749 750
  if (is_open())
  {
    uint length;

751
    if (reinit_io_cache(cache, READ_CACHE, 0, 0, 0))
752
    {
753
      sql_print_error(ER(ER_ERROR_ON_WRITE), cache->file_name, errno);
754 755
      goto err;
    }
756 757
    length=my_b_bytes_in_cache(cache);
    do
758 759
    {
      if (my_b_write(&log_file, cache->rc_pos, length))
760
      {
761
	if (!write_error)
762
	  sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
763
	goto err;
764
      }
765
      cache->rc_pos=cache->rc_end;		// Mark buffer used up
766
    } while ((length=my_b_fill(cache)));
767 768 769
    if (flush_io_cache(&log_file))
    {
      if (!write_error)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
770
	sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
771 772 773 774
      goto err;
    }
    if (cache->error)				// Error on read
    {
775
      sql_print_error(ER(ER_ERROR_ON_READ), cache->file_name, errno);
776
      goto err;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
777 778
    }
  }
779 780 781 782 783 784 785 786
  error=0;

err:
  if (error)
    write_error=1;
  else
    VOID(pthread_cond_broadcast(&COND_binlog_update));
    
787 788
  VOID(pthread_mutex_unlock(&LOCK_log));
  
789
  return error;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
790 791
}

792

bk@work.mysql.com's avatar
bk@work.mysql.com committed
793 794
/* Write update log in a format suitable for incremental backup */

795
bool MYSQL_LOG::write(THD *thd,const char *query, uint query_length,
796
		      time_t query_start)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
797
{
798
  bool error=0;
799
  if (is_open())
bk@work.mysql.com's avatar
bk@work.mysql.com committed
800
  {
801
    time_t current_time;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
802
    VOID(pthread_mutex_lock(&LOCK_log));
803
    if (is_open())
bk@work.mysql.com's avatar
bk@work.mysql.com committed
804
    {						// Safety agains reopen
805
      int tmp_errno=0;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
806 807 808 809 810 811
      char buff[80],*end;
      end=buff;
      if (!(thd->options & OPTION_UPDATE_LOG) &&
	  (thd->master_access & PROCESS_ACL))
      {
	VOID(pthread_mutex_unlock(&LOCK_log));
812
	return 0;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
813
      }
814
      if ((specialflag & SPECIAL_LONG_LOG_FORMAT) || query_start)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
815
      {
816 817
	current_time=time(NULL);
	if (current_time != last_time)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
818
	{
819
	  last_time=current_time;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
820 821
	  struct tm tm_tmp;
	  struct tm *start;
822
	  localtime_r(&current_time,&tm_tmp);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
823
	  start=&tm_tmp;
824 825 826 827 828 829 830 831
	  /* 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);
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
832
	  if (my_b_write(&log_file, (byte*) buff,24))
833
	    tmp_errno=errno;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
834
	}
835
	if (my_b_printf(&log_file, "# User@Host: %s[%s] @ %s [%s]\n",
836 837 838
			thd->priv_user,
			thd->user,
			thd->host ? thd->host : "",
839
			thd->ip ? thd->ip : "") == (uint) -1)
840
	  tmp_errno=errno;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
841
      }
842 843 844
      if (query_start)
      {
	/* For slow query log */
845
	if (my_b_printf(&log_file,
846
			"# Time: %lu  Lock_time: %lu  Rows_sent: %lu  Rows_examined: %lu\n",
847 848
			(ulong) (current_time - query_start),
			(ulong) (thd->time_after_lock - query_start),
849 850 851
			(ulong) thd->sent_row_count,
			(ulong) thd->examined_row_count) == (uint) -1)
	  tmp_errno=errno;
852
      }
bk@work.mysql.com's avatar
bk@work.mysql.com committed
853 854
      if (thd->db && strcmp(thd->db,db))
      {						// Database changed
855
	if (my_b_printf(&log_file,"use %s;\n",thd->db) == (uint) -1)
856
	  tmp_errno=errno;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
857 858 859 860 861 862 863 864 865 866 867 868 869 870 871 872 873 874 875 876 877 878 879 880 881 882 883 884 885 886
	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;
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
887 888
	if (my_b_write(&log_file, (byte*) "SET ",4) ||
	    my_b_write(&log_file, (byte*) buff+1,(uint) (end-buff)-1))
889
	  tmp_errno=errno;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
890 891 892 893 894 895
      }
      if (!query)
      {
	query="#adminstrator command";
	query_length=21;
      }
monty@donna.mysql.com's avatar
monty@donna.mysql.com committed
896 897
      if (my_b_write(&log_file, (byte*) query,query_length) ||
	  my_b_write(&log_file, (byte*) ";\n",2) ||
898
	  flush_io_cache(&log_file))
899 900
	tmp_errno=errno;
      if (tmp_errno)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
901
      {
902 903 904 905 906 907
	error=1;
	if (! write_error)
	{
	  write_error=1;
	  sql_print_error(ER(ER_ERROR_ON_WRITE),name,error);
	}
bk@work.mysql.com's avatar
bk@work.mysql.com committed
908 909 910 911
      }
    }
    VOID(pthread_mutex_unlock(&LOCK_log));
  }
912
  return error;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
913 914 915 916 917
}


void MYSQL_LOG::close(bool exiting)
{					// One can't set log_type here!
918
  if (is_open())
bk@work.mysql.com's avatar
bk@work.mysql.com committed
919
  {
920
    File file=log_file.file;
bk@work.mysql.com's avatar
bk@work.mysql.com committed
921 922 923
    if (log_type == LOG_BIN)
    {
      Stop_log_event s;
924
      s.set_log_seq(0, this);
925
      s.write(&log_file);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
926 927
      VOID(pthread_cond_broadcast(&COND_binlog_update));
    }
928 929
    end_io_cache(&log_file);
    if (my_close(file,MYF(0)) < 0 && ! write_error)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
930 931 932 933 934
    {
      write_error=1;
      sql_print_error(ER(ER_ERROR_ON_WRITE),name,errno);
    }
  }
935
  if (exiting && index_file >= 0)
936
  {
937
    if (my_close(index_file,MYF(0)) < 0 && ! write_error)
bk@work.mysql.com's avatar
bk@work.mysql.com committed
938
    {
939 940
      write_error=1;
      sql_print_error(ER(ER_ERROR_ON_WRITE),name,errno);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
941
    }
942 943
    index_file=-1;
    log_type=LOG_CLOSED;
944
  }
945
  safeFree(name);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
946 947 948 949 950 951 952 953 954 955 956 957 958 959 960 961 962 963 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
}


	/* 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];
997
    my_vsnprintf(buff,sizeof(buff)-1,format,args);
bk@work.mysql.com's avatar
bk@work.mysql.com committed
998 999 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029
    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
}