~ps10gel/ubuntu/xenial/trafficserver/6.2.0

« back to all changes in this revision

Viewing changes to proxy/logging/LogFile.cc

  • Committer: Bazaar Package Importer
  • Author(s): Arno Toell
  • Date: 2011-01-13 11:49:18 UTC
  • Revision ID: james.westby@ubuntu.com-20110113114918-vu422h8dknrgkj15
Tags: upstream-2.1.5-unstable
ImportĀ upstreamĀ versionĀ 2.1.5-unstable

Show diffs side-by-side

added added

removed removed

Lines of Context:
 
1
/** @file
 
2
 
 
3
  A brief file description
 
4
 
 
5
  @section license License
 
6
 
 
7
  Licensed to the Apache Software Foundation (ASF) under one
 
8
  or more contributor license agreements.  See the NOTICE file
 
9
  distributed with this work for additional information
 
10
  regarding copyright ownership.  The ASF licenses this file
 
11
  to you under the Apache License, Version 2.0 (the
 
12
  "License"); you may not use this file except in compliance
 
13
  with the License.  You may obtain a copy of the License at
 
14
 
 
15
      http://www.apache.org/licenses/LICENSE-2.0
 
16
 
 
17
  Unless required by applicable law or agreed to in writing, software
 
18
  distributed under the License is distributed on an "AS IS" BASIS,
 
19
  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 
20
  See the License for the specific language governing permissions and
 
21
  limitations under the License.
 
22
 */
 
23
 
 
24
/***************************************************************************
 
25
 LogFile.cc
 
26
 
 
27
 
 
28
 ***************************************************************************/
 
29
 
 
30
#include "libts.h"
 
31
#include "ink_unused.h"
 
32
 
 
33
#include <errno.h>
 
34
#include <sys/types.h>
 
35
#include <sys/stat.h>
 
36
#include <fcntl.h>
 
37
 
 
38
#include "Error.h"
 
39
 
 
40
#include "P_EventSystem.h"
 
41
#include "I_Machine.h"
 
42
#include "LogSock.h"
 
43
 
 
44
#include "LogLimits.h"
 
45
#include "LogField.h"
 
46
#include "LogFilter.h"
 
47
#include "LogFormat.h"
 
48
#include "LogBuffer.h"
 
49
#include "LogBufferV1.h"
 
50
#include "LogFile.h"
 
51
#include "LogHost.h"
 
52
#include "LogObject.h"
 
53
#include "LogUtils.h"
 
54
#include "LogConfig.h"
 
55
#include "Log.h"
 
56
 
 
57
// the FILESIZE_SAFE_THRESHOLD_FACTOR is used to compute the file size
 
58
// limit as follows:
 
59
//
 
60
// size_limit = system_filesize_limit -
 
61
//              FILESIZE_SAFE_THRESHOLD_FACTOR * log_buffer_size
 
62
//
 
63
// where system_filesize_limit is the current filesize limit as returned by
 
64
// getrlimit(), and log_buffer_size is the config. value for the size of
 
65
// a LogBuffer.
 
66
//
 
67
// This means that a file reaches its size_limit once it has no room to fit
 
68
// FILESIZE_SAFE_THRESHOLD_FACTOR LogBuffers.
 
69
//
 
70
// A LogBuffer, when converted to ascii, can produce more than
 
71
// log_buffer_size bytes, depending on the type of the logging fields it
 
72
// stores. String fields don't change size, but integer fields do.
 
73
// A 32 bit integer has a maximum value of 10 digits, which means it
 
74
// can grow by a factor of 10/4 = 2.5 when translated to ascii.
 
75
// Assuming all fields in a LogBuffer are (32 bit) integers, the maximum
 
76
// amount of ascii data a LogBuffer can produce is 2.5 times its size, so
 
77
// we should make sure we can always write this amount to a file.
 
78
//
 
79
// However, to be extra safe, we should set the
 
80
// FILESIZE_SAFE_THRESHOLD_FACTOR higher than 3
 
81
//
 
82
static const int FILESIZE_SAFE_THRESHOLD_FACTOR = 10;
 
83
 
 
84
/*-------------------------------------------------------------------------
 
85
  LogFile::LogFile
 
86
 
 
87
  This constructor builds a LogFile object given the path, filename, header,
 
88
  and logfile format type.  This is the common way to create a new logfile.
 
89
  -------------------------------------------------------------------------*/
 
90
 
 
91
LogFile::LogFile(const char *name, const char *header, LogFileFormat format,
 
92
                 uint64_t signature, size_t ascii_buffer_size, size_t max_line_size, size_t overspill_report_count)
 
93
  :
 
94
m_file_format(format),
 
95
m_name(xstrdup(name)),
 
96
m_header(xstrdup(header)),
 
97
m_signature(signature),
 
98
m_meta_info(NULL),
 
99
m_max_line_size(max_line_size),
 
100
m_overspill_report_count(overspill_report_count)
 
101
{
 
102
  init();
 
103
  m_ascii_buffer_size = (ascii_buffer_size < max_line_size ? max_line_size : ascii_buffer_size);
 
104
  m_ascii_buffer = NEW(new char[m_ascii_buffer_size]);
 
105
  m_overspill_buffer = NEW(new char[m_max_line_size]);
 
106
 
 
107
  Debug("log-file", "exiting LogFile constructor, m_name=%s, this=%p", m_name, this);
 
108
}
 
109
 
 
110
void
 
111
LogFile::init()
 
112
{
 
113
  delete m_meta_info;
 
114
  m_meta_info = NULL;
 
115
  m_overspill_bytes = 0;
 
116
  m_overspill_written = 0;
 
117
  m_attempts_to_write_overspill = 0;
 
118
  m_fd = -1;
 
119
  m_start_time = 0L;
 
120
  m_end_time = 0L;
 
121
  m_bytes_written = 0;
 
122
  m_size_bytes = 0;
 
123
  m_has_size_limit = false;
 
124
  m_size_limit_bytes = 0;
 
125
  m_filesystem_checks_done = false;
 
126
}
 
127
 
 
128
/*-------------------------------------------------------------------------
 
129
  LogFile::~LogFile
 
130
  -------------------------------------------------------------------------*/
 
131
 
 
132
LogFile::~LogFile()
 
133
{
 
134
  Debug("log-file", "entering LogFile destructor, this=%p", this);
 
135
  close_file();
 
136
 
 
137
  xfree(m_name);
 
138
  xfree(m_header);
 
139
  delete m_meta_info;
 
140
  delete[]m_ascii_buffer;
 
141
  m_ascii_buffer = 0;
 
142
  delete[]m_overspill_buffer;
 
143
  m_overspill_buffer = 0;
 
144
  Debug("log-file", "exiting LogFile destructor, this=%p", this);
 
145
}
 
146
 
 
147
/*-------------------------------------------------------------------------
 
148
  LogFile::exists
 
149
 
 
150
  Returns true if the logfile already exists; false otherwise.
 
151
  -------------------------------------------------------------------------*/
 
152
 
 
153
bool LogFile::exists(const char *pathname)
 
154
{
 
155
  return (::access(pathname, F_OK) == 0);
 
156
}
 
157
 
 
158
/*-------------------------------------------------------------------------
 
159
  LogFile::change_name
 
160
  -------------------------------------------------------------------------*/
 
161
 
 
162
void
 
163
LogFile::change_name(char *new_name)
 
164
{
 
165
  xfree(m_name);
 
166
  m_name = xstrdup(new_name);
 
167
}
 
168
 
 
169
/*-------------------------------------------------------------------------
 
170
  LogFile::change_header
 
171
  -------------------------------------------------------------------------*/
 
172
 
 
173
void
 
174
LogFile::change_header(const char *header)
 
175
{
 
176
  xfree(m_header);
 
177
  m_header = xstrdup(header);
 
178
}
 
179
 
 
180
/*-------------------------------------------------------------------------
 
181
  LogFile::open
 
182
 
 
183
  Open the logfile for append access.  This will create a logfile if the
 
184
  file does not already exist.
 
185
  -------------------------------------------------------------------------*/
 
186
 
 
187
int
 
188
LogFile::open_file()
 
189
{
 
190
  if (is_open()) {
 
191
    return LOG_FILE_NO_ERROR;
 
192
  }
 
193
 
 
194
  if (m_name && !strcmp(m_name, "stdout")) {
 
195
    m_fd = STDOUT_FILENO;
 
196
    return LOG_FILE_NO_ERROR;
 
197
  }
 
198
  //
 
199
  // Check to see if the file exists BEFORE we try to open it, since
 
200
  // opening it will also create it.
 
201
  //
 
202
  bool file_exists = LogFile::exists(m_name);
 
203
 
 
204
  if (file_exists) {
 
205
    if (!m_meta_info) {
 
206
      // This object must be fresh since it has not built its MetaInfo
 
207
      // so we create a new MetaInfo object that will read right away
 
208
      // (in the constructor) the corresponding metafile
 
209
      //
 
210
      m_meta_info = new MetaInfo(m_name);
 
211
    }
 
212
  } else {
 
213
    // The log file does not exist, so we create a new MetaInfo object
 
214
    //  which will save itself to disk right away (in the constructor)
 
215
    m_meta_info = new MetaInfo(m_name, LogUtils::timestamp(), m_signature);
 
216
  }
 
217
 
 
218
  int flags, perms;
 
219
 
 
220
  if (m_file_format == ASCII_PIPE) {
 
221
#ifdef ASCII_PIPE_FORMAT_SUPPORTED
 
222
    if (mknod(m_name, S_IFIFO | S_IRUSR | S_IWUSR, 0) < 0) {
 
223
      if (errno != EEXIST) {
 
224
        Error("Could not create named pipe %s for logging: %s", m_name, strerror(errno));
 
225
        return LOG_FILE_COULD_NOT_CREATE_PIPE;
 
226
      }
 
227
    } else {
 
228
      Debug("log-file", "Created named pipe %s for logging", m_name);
 
229
    }
 
230
    flags = O_WRONLY | O_NDELAY;
 
231
    perms = 0;
 
232
#else
 
233
    Error("ASCII_PIPE mode not supported, could not create named pipe %s" " for logging", m_name);
 
234
    return LOG_FILE_PIPE_MODE_NOT_SUPPORTED;
 
235
#endif
 
236
  } else {
 
237
    flags = O_WRONLY | O_APPEND | O_CREAT;
 
238
    perms = Log::config->logfile_perm;
 
239
  }
 
240
 
 
241
  Debug("log-file", "attempting to open %s", m_name);
 
242
  m_fd =::open(m_name, flags, perms);
 
243
 
 
244
  if (m_fd < 0) {
 
245
    // if error happened because no process is reading the pipe don't
 
246
    // complain, otherwise issue an error message
 
247
    //
 
248
    if (errno != ENXIO) {
 
249
      Error("Error opening log file %s: %s", m_name, strerror(errno));
 
250
      return LOG_FILE_COULD_NOT_OPEN_FILE;
 
251
    }
 
252
    Debug("log-file", "no readers for pipe %s", m_name);
 
253
    return LOG_FILE_NO_PIPE_READERS;
 
254
  }
 
255
 
 
256
  int e = do_filesystem_checks();
 
257
  if (e != 0) {
 
258
    m_fd = -1;                  // reset to error condition
 
259
    return LOG_FILE_FILESYSTEM_CHECKS_FAILED;
 
260
  }
 
261
 
 
262
  Debug("log-file", "LogFile %s is now open (fd=%d)", m_name, m_fd);
 
263
 
 
264
  //
 
265
  // If we've opened the file and it didn't already exist, then this is a
 
266
  // "new" file and we need to make some initializations.  This is the
 
267
  // time to write any headers and do any one-time initialization of the
 
268
  // file.
 
269
  //
 
270
  if (!file_exists) {
 
271
    if (m_file_format != BINARY_LOG && m_header != NULL) {
 
272
      Debug("log-file", "writing header to LogFile %s", m_name);
 
273
      writeln(m_header, strlen(m_header), m_fd, m_name);
 
274
    }
 
275
  }
 
276
  // we use SUM_GLOBAL_DYN_STAT because INCREMENT_DYN_STAT
 
277
  // would increment only the statistics for the flush thread (where we
 
278
  // are running) and these won't be visible Traffic Manager
 
279
  LOG_SUM_GLOBAL_DYN_STAT(log_stat_log_files_open_stat, 1);
 
280
 
 
281
  return LOG_FILE_NO_ERROR;
 
282
}
 
283
 
 
284
/*-------------------------------------------------------------------------
 
285
  LogFile::close
 
286
 
 
287
  Close the current logfile.
 
288
  -------------------------------------------------------------------------*/
 
289
 
 
290
void
 
291
LogFile::close_file()
 
292
{
 
293
  if (is_open()) {
 
294
    ::close(m_fd);
 
295
    Debug("log-file", "LogFile %s (fd=%d) is closed", m_name, m_fd);
 
296
    m_fd = -1;
 
297
 
 
298
    // we use SUM_GLOBAL_DYN_STAT because DECREMENT_DYN_STAT
 
299
    // would decrement only the statistics for the flush thread (where we
 
300
    // are running) and these won't be visible in Traffic Manager
 
301
    LOG_SUM_GLOBAL_DYN_STAT(log_stat_log_files_open_stat, -1);
 
302
  }
 
303
  m_filesystem_checks_done = false;
 
304
}
 
305
 
 
306
/*-------------------------------------------------------------------------
 
307
  LogFile::rolled_logfile
 
308
 
 
309
  This function will return true if the given filename corresponds to a
 
310
  rolled logfile.  We make this determination based on the file extension.
 
311
  -------------------------------------------------------------------------*/
 
312
 
 
313
bool LogFile::rolled_logfile(char *path)
 
314
{
 
315
  const int
 
316
    target_len = (int) strlen(LOGFILE_ROLLED_EXTENSION);
 
317
  int
 
318
    len = (int) strlen(path);
 
319
  if (len > target_len) {
 
320
    char *
 
321
      str = &path[len - target_len];
 
322
    if (!strcmp(str, LOGFILE_ROLLED_EXTENSION)) {
 
323
      return true;
 
324
    }
 
325
  }
 
326
  return false;
 
327
}
 
328
 
 
329
/*-------------------------------------------------------------------------
 
330
  LogFile::roll
 
331
 
 
332
  This function is called by a LogObject to roll its files.  The
 
333
  tricky part to this routine is in coming up with the new file name,
 
334
  which contains the bounding timestamp interval for the entries
 
335
  within the file.
 
336
 
 
337
  Under normal operating conditions, this LogFile object was in existence
 
338
  for all writes to the file.  In this case, the LogFile members m_start_time
 
339
  and m_end_time will have the starting and ending times for the actual
 
340
  entries written to the file.
 
341
 
 
342
  On restart situations, it is possible to re-open an existing logfile,
 
343
  which means that the m_start_time variable will be later than the actual
 
344
  entries recorded in the file.  In this case, we'll use the creation time
 
345
  of the file, which should be recorded in the meta-information located on
 
346
  disk.
 
347
 
 
348
  If we can't use the meta-file, either because it's not there or because
 
349
  it's not valid, then we'll use timestamp 0 (Jan 1, 1970) as the starting
 
350
  bound.
 
351
 
 
352
  Return 1 if file rolled, 0 otherwise
 
353
  -------------------------------------------------------------------------*/
 
354
 
 
355
int
 
356
LogFile::roll(long interval_start, long interval_end)
 
357
{
 
358
  //
 
359
  // First, let's see if a roll is even needed.
 
360
  //
 
361
  if (m_name == NULL || !LogFile::exists(m_name)) {
 
362
    Debug("log-file", "Roll not needed for %s; file doesn't exist", (m_name) ? m_name : "no_name");
 
363
    return 0;
 
364
  }
 
365
  // Read meta info if needed (if file was not opened)
 
366
  //
 
367
  if (!m_meta_info) {
 
368
    m_meta_info = new MetaInfo(m_name);
 
369
  }
 
370
  //
 
371
  // Create the new file name, which consists of a timestamp and rolled
 
372
  // extension added to the previous file name.  The timestamp format is
 
373
  // ".%Y%m%d.%Hh%Mm%Ss-%Y%m%d.%Hh%Mm%Ss", where the two date/time values
 
374
  // represent the starting and ending times for entries in the rolled
 
375
  // log file.  In addition, we add the hostname.  So, the entire rolled
 
376
  // format is something like:
 
377
  //
 
378
  //    "squid.log.mymachine.19980712.12h00m00s-19980713.12h00m00s.old"
 
379
  //
 
380
  char roll_name[MAXPATHLEN];
 
381
  char start_time_ext[64];
 
382
  char end_time_ext[64];
 
383
  time_t start, end;
 
384
 
 
385
  //
 
386
  // Make sure the file is closed so we don't leak any descriptors.
 
387
  //
 
388
  close_file();
 
389
 
 
390
  //
 
391
  // Start with conservative values for the start and end bounds, then
 
392
  // try to refine.
 
393
  //
 
394
  start = 0L;
 
395
  end = (interval_end >= m_end_time) ? interval_end : m_end_time;
 
396
 
 
397
  if (m_meta_info->data_from_metafile()) {
 
398
    //
 
399
    // If the metadata came from the metafile, this means that
 
400
    // the file was preexisting, so we can't use m_start_time for
 
401
    // our starting bounds.  Instead, we'll try to use the file
 
402
    // creation time stored in the metafile (if it's valid and we can
 
403
    // read it).  If all else fails, we'll use 0 for the start time.
 
404
    //
 
405
    m_meta_info->get_creation_time(&start);
 
406
  } else {
 
407
    //
 
408
    // The logfile was not preexisting (normal case), so we'll use
 
409
    // earlier of the interval start time and the m_start_time.
 
410
    //
 
411
    // note that m_start_time is not the time of the first
 
412
    // transaction, but the time of the creation of the first log
 
413
    // buffer used by the file. These times may be different,
 
414
    // especially under light load, and using the m_start_time may
 
415
    // produce overlapping filenames (the problem is that we have
 
416
    // no easy way of keeping track of the timestamp of the first
 
417
    // transaction
 
418
    //
 
419
    start = (m_start_time < interval_start) ? m_start_time : interval_start;
 
420
  }
 
421
 
 
422
  //
 
423
  // Now that we have our timestamp values, convert them to the proper
 
424
  // timestamp formats and create the rolled file name.
 
425
  //
 
426
  LogUtils::timestamp_to_str((long) start, start_time_ext, 64);
 
427
  LogUtils::timestamp_to_str((long) end, end_time_ext, 64);
 
428
  snprintf(roll_name, MAXPATHLEN, "%s%s%s.%s-%s%s",
 
429
               m_name,
 
430
               LOGFILE_SEPARATOR_STRING,
 
431
               this_machine()->hostname, start_time_ext, end_time_ext, LOGFILE_ROLLED_EXTENSION);
 
432
 
 
433
  //
 
434
  // It may be possible that the file we want to roll into already
 
435
  // exists.  If so, then we need to add a version tag to the rolled
 
436
  // filename as well so that we don't clobber existing files.
 
437
  //
 
438
 
 
439
  int version = 1;
 
440
  while (LogFile::exists(roll_name)) {
 
441
    Note("The rolled file %s already exists; adding version "
 
442
         "tag %d to avoid clobbering the existing file.", roll_name, version);
 
443
    snprintf(roll_name, MAXPATHLEN, "%s%s%s.%s-%s.%d%s",
 
444
                 m_name,
 
445
                 LOGFILE_SEPARATOR_STRING,
 
446
                 this_machine()->hostname, start_time_ext, end_time_ext, version, LOGFILE_ROLLED_EXTENSION);
 
447
    version++;
 
448
  }
 
449
 
 
450
  //
 
451
  // It's now safe to rename the file.
 
452
  //
 
453
 
 
454
  if (::rename(m_name, roll_name) < 0) {
 
455
    Warning("Traffic Server could not rename logfile %s to %s, error %d: "
 
456
            "%s.", m_name, roll_name, errno, strerror(errno));
 
457
    return 0;
 
458
  }
 
459
  // reset m_start_time
 
460
  //
 
461
  m_start_time = 0;
 
462
 
 
463
  Status("The logfile %s was rolled to %s.", m_name, roll_name);
 
464
 
 
465
  return 1;
 
466
}
 
467
 
 
468
/*-------------------------------------------------------------------------
 
469
  LogFile::write
 
470
 
 
471
  Write the given LogBuffer data onto this file
 
472
  -------------------------------------------------------------------------*/
 
473
int
 
474
LogFile::write(LogBuffer * lb, size_t * to_disk, size_t * to_net, size_t * to_pipe)
 
475
{
 
476
  NOWARN_UNUSED(to_net);
 
477
  if (lb == NULL) {
 
478
    Note("Cannot write LogBuffer to LogFile %s; LogBuffer is NULL", m_name);
 
479
    return -1;
 
480
  }
 
481
  LogBufferHeader *buffer_header = lb->header();
 
482
  if (buffer_header == NULL) {
 
483
    Note("Cannot write LogBuffer to LogFile %s; LogBufferHeader is NULL", m_name);
 
484
    return -1;
 
485
  }
 
486
  if (buffer_header->entry_count == 0) {
 
487
    // no bytes to write
 
488
    Note("LogBuffer with 0 entries for LogFile %s, nothing to write", m_name);
 
489
    return 0;
 
490
  }
 
491
  // check if size limit has been exceeded and roll file if that is the case
 
492
 
 
493
  if (size_limit_exceeded()) {
 
494
    Warning("File %s will be rolled because its size is close to "
 
495
            "or exceeds the operating system filesize limit", get_name());
 
496
    roll(0, LogUtils::timestamp());
 
497
  }
 
498
  // make sure we're open & ready to write
 
499
 
 
500
  check_fd();
 
501
  if (!is_open()) {
 
502
    return -1;
 
503
  }
 
504
 
 
505
  int bytes = 0;
 
506
  if (m_file_format == BINARY_LOG) {
 
507
    //
 
508
    // Ok, now we need to write the binary buffer to the file, and we
 
509
    // can do so in one swift write.  The question is, do we write the
 
510
    // LogBufferHeader with each buffer or not?  The answer is yes.
 
511
    // Even though we'll be puttint down redundant data (things that
 
512
    // don't change between buffers), it's not worth trying to separate
 
513
    // out the buffer-dependent data from the buffer-independent data.
 
514
    //
 
515
    if (!Log::config->logging_space_exhausted) {
 
516
      bytes = writeln((char *) buffer_header, buffer_header->byte_count, m_fd, m_name);
 
517
      if (bytes > 0 && to_disk) {
 
518
        *to_disk += bytes;
 
519
      }
 
520
    }
 
521
  } else if (m_file_format == ASCII_LOG) {
 
522
    bytes = write_ascii_logbuffer3(buffer_header);
 
523
    if (bytes > 0 && to_disk) {
 
524
      *to_disk += bytes;
 
525
    }
 
526
#if defined(LOG_BUFFER_TRACKING)
 
527
    Debug("log-buftrak", "[%d]LogFile::write - ascii write complete", buffer_header->id);
 
528
#endif // defined(LOG_BUFFER_TRACKING)
 
529
  } else if (m_file_format == ASCII_PIPE) {
 
530
    bytes = write_ascii_logbuffer3(buffer_header);
 
531
    if (bytes > 0 && to_pipe) {
 
532
      *to_pipe += bytes;
 
533
    }
 
534
#if defined(LOG_BUFFER_TRACKING)
 
535
    Debug("log-buftrak", "[%d]LogFile::write - ascii pipe write complete", buffer_header->id);
 
536
#endif // defined(LOG_BUFFER_TRACKING)
 
537
  } else {
 
538
    Error("Cannot write LogBuffer to LogFile %s; invalid file format: %d", m_name, m_file_format);
 
539
    return -1;
 
540
  }
 
541
 
 
542
  //
 
543
  // If the start time for this file has yet to be established, then grab
 
544
  // the low_timestamp from the given LogBuffer.  Then, we always set the
 
545
  // end time to the high_timestamp, so it's always up to date.
 
546
  //
 
547
 
 
548
  if (!m_start_time)
 
549
    m_start_time = buffer_header->low_timestamp;
 
550
  m_end_time = buffer_header->high_timestamp;
 
551
 
 
552
  // update bytes written and file size (if not a pipe)
 
553
  //
 
554
  m_bytes_written += bytes;
 
555
  if (m_file_format != ASCII_PIPE) {
 
556
    m_size_bytes += bytes;
 
557
  }
 
558
 
 
559
  return bytes;
 
560
}
 
561
 
 
562
/*-------------------------------------------------------------------------
 
563
  LogFile::write_ascii_logbuffer
 
564
 
 
565
  This routine takes the given LogBuffer and writes it (in ASCII) to the
 
566
  given file descriptor.  Written as a stand-alone function, it can be
 
567
  called from either the local LogBuffer::write routine from inside of the
 
568
  proxy, or from an external program (since it is a static function).  The
 
569
  return value is the number of bytes written.
 
570
  -------------------------------------------------------------------------*/
 
571
 
 
572
int
 
573
LogFile::write_ascii_logbuffer(LogBufferHeader * buffer_header, int fd, const char *path, char *alt_format)
 
574
{
 
575
  ink_assert(buffer_header != NULL);
 
576
  ink_assert(fd >= 0);
 
577
 
 
578
  char fmt_buf[LOG_MAX_FORMATTED_BUFFER];
 
579
  char fmt_line[LOG_MAX_FORMATTED_LINE];
 
580
  LogBufferIterator iter(buffer_header);
 
581
  LogEntryHeader *entry_header;
 
582
  int fmt_buf_bytes = 0;
 
583
  int fmt_line_bytes = 0;
 
584
  int bytes = 0;
 
585
 
 
586
  LogBufferHeaderV1 *v1_buffer_header;
 
587
  LogFormatType format_type;
 
588
  char *fieldlist_str;
 
589
  char *printf_str;
 
590
 
 
591
  switch (buffer_header->version) {
 
592
  case LOG_SEGMENT_VERSION:
 
593
    format_type = (LogFormatType) buffer_header->format_type;
 
594
 
 
595
    fieldlist_str = buffer_header->fmt_fieldlist();
 
596
    printf_str = buffer_header->fmt_printf();
 
597
    break;
 
598
 
 
599
  case 1:
 
600
    v1_buffer_header = (LogBufferHeaderV1 *) buffer_header;
 
601
    format_type = (LogFormatType) v1_buffer_header->format_type;
 
602
    fieldlist_str = v1_buffer_header->symbol_str;
 
603
    printf_str = v1_buffer_header->printf_str;
 
604
    break;
 
605
 
 
606
  default:
 
607
    Note("Invalid LogBuffer version %d in write_ascii_logbuffer; "
 
608
         "current version is %d", buffer_header->version, LOG_SEGMENT_VERSION);
 
609
    return 0;
 
610
  }
 
611
 
 
612
  while ((entry_header = iter.next())) {
 
613
 
 
614
    fmt_line_bytes = LogBuffer::to_ascii(entry_header, format_type,
 
615
                                         &fmt_line[0], LOG_MAX_FORMATTED_LINE,
 
616
                                         fieldlist_str, printf_str, buffer_header->version, alt_format);
 
617
    ink_debug_assert(fmt_line_bytes > 0);
 
618
 
 
619
    if (fmt_line_bytes > 0) {
 
620
      if ((fmt_line_bytes + fmt_buf_bytes) >= LOG_MAX_FORMATTED_BUFFER) {
 
621
        if (!Log::config->logging_space_exhausted) {
 
622
          bytes += writeln(fmt_buf, fmt_buf_bytes, fd, path);
 
623
        }
 
624
        fmt_buf_bytes = 0;
 
625
      }
 
626
      ink_debug_assert(fmt_buf_bytes < LOG_MAX_FORMATTED_BUFFER);
 
627
      ink_debug_assert(fmt_line_bytes < LOG_MAX_FORMATTED_BUFFER - fmt_buf_bytes);
 
628
      memcpy(&fmt_buf[fmt_buf_bytes], fmt_line, fmt_line_bytes);
 
629
      fmt_buf_bytes += fmt_line_bytes;
 
630
      ink_debug_assert(fmt_buf_bytes < LOG_MAX_FORMATTED_BUFFER);
 
631
      fmt_buf[fmt_buf_bytes] = '\n';    // keep entries separate
 
632
      fmt_buf_bytes += 1;
 
633
    }
 
634
  }
 
635
  if (fmt_buf_bytes > 0) {
 
636
    if (!Log::config->logging_space_exhausted) {
 
637
      ink_debug_assert(fmt_buf_bytes < LOG_MAX_FORMATTED_BUFFER);
 
638
      bytes += writeln(fmt_buf, fmt_buf_bytes, fd, path);
 
639
    }
 
640
  }
 
641
 
 
642
  return bytes;
 
643
}
 
644
 
 
645
int
 
646
LogFile::write_ascii_logbuffer3(LogBufferHeader * buffer_header, char *alt_format)
 
647
{
 
648
  Debug("log-file", "entering LogFile::write_ascii_logbuffer3 for %s " "(this=%p)", m_name, this);
 
649
  ink_debug_assert(buffer_header != NULL);
 
650
  ink_debug_assert(m_fd >= 0);
 
651
 
 
652
  LogBufferIterator iter(buffer_header);
 
653
  LogEntryHeader *entry_header;
 
654
  int fmt_buf_bytes = 0;
 
655
  int total_bytes = 0;
 
656
 
 
657
  LogBufferHeaderV1 *v1_buffer_header;
 
658
  LogFormatType format_type;
 
659
  char *fieldlist_str;
 
660
  char *printf_str;
 
661
 
 
662
  switch (buffer_header->version) {
 
663
  case LOG_SEGMENT_VERSION:
 
664
    format_type = (LogFormatType) buffer_header->format_type;
 
665
    fieldlist_str = buffer_header->fmt_fieldlist();
 
666
    printf_str = buffer_header->fmt_printf();
 
667
    break;
 
668
 
 
669
  case 1:
 
670
    v1_buffer_header = (LogBufferHeaderV1 *) buffer_header;
 
671
    format_type = (LogFormatType) v1_buffer_header->format_type;
 
672
    fieldlist_str = v1_buffer_header->symbol_str;
 
673
    printf_str = v1_buffer_header->printf_str;
 
674
    break;
 
675
 
 
676
  default:
 
677
    Note("Invalid LogBuffer version %d in write_ascii_logbuffer; "
 
678
         "current version is %d", buffer_header->version, LOG_SEGMENT_VERSION);
 
679
    return 0;
 
680
  }
 
681
 
 
682
  while ((entry_header = iter.next())) {
 
683
    fmt_buf_bytes = 0;
 
684
 
 
685
    // fill the buffer with as many records as possible
 
686
    //
 
687
    do {
 
688
      if (m_ascii_buffer_size - fmt_buf_bytes >= m_max_line_size) {
 
689
        int bytes = LogBuffer::to_ascii(entry_header, format_type,
 
690
                                        &m_ascii_buffer[fmt_buf_bytes],
 
691
                                        m_max_line_size - 1,
 
692
                                        fieldlist_str, printf_str,
 
693
                                        buffer_header->version,
 
694
                                        alt_format);
 
695
 
 
696
        if (bytes > 0) {
 
697
          fmt_buf_bytes += bytes;
 
698
          m_ascii_buffer[fmt_buf_bytes] = '\n';
 
699
          ++fmt_buf_bytes;
 
700
        }
 
701
        // if writing to a pipe, fill the buffer with a single
 
702
        // record to avoid as much as possible overflowing the
 
703
        // pipe buffer
 
704
        //
 
705
        if (m_file_format == ASCII_PIPE)
 
706
          break;
 
707
      }
 
708
    } while ((entry_header = iter.next()));
 
709
 
 
710
    ssize_t bytes_written;
 
711
 
 
712
    // try to write any data that may not have been written in a
 
713
    // previous attempt
 
714
    //
 
715
    if (m_overspill_bytes) {
 
716
      bytes_written = 0;
 
717
      if (!Log::config->logging_space_exhausted) {
 
718
        bytes_written =::write(m_fd, &m_overspill_buffer[m_overspill_written], m_overspill_bytes);
 
719
      }
 
720
      if (bytes_written < 0) {
 
721
        Error("An error was encountered in writing to %s: %s.", ((m_name) ? m_name : "logfile"), strerror(errno));
 
722
      } else {
 
723
        m_overspill_bytes -= bytes_written;
 
724
        m_overspill_written += bytes_written;
 
725
      }
 
726
 
 
727
      if (m_overspill_bytes) {
 
728
        ++m_attempts_to_write_overspill;
 
729
        if (m_overspill_report_count && (m_attempts_to_write_overspill % m_overspill_report_count == 0)) {
 
730
          Warning("Have dropped %u records so far because buffer "
 
731
                  "for %s is full", m_attempts_to_write_overspill, m_name);
 
732
        }
 
733
      } else if (m_attempts_to_write_overspill) {
 
734
        Warning("Dropped %u records because buffer for %s was full", m_attempts_to_write_overspill, m_name);
 
735
        m_attempts_to_write_overspill = 0;
 
736
      }
 
737
    }
 
738
    // write the buffer out to the file or pipe
 
739
    //
 
740
    if (fmt_buf_bytes && !m_overspill_bytes) {
 
741
      bytes_written = 0;
 
742
      if (!Log::config->logging_space_exhausted) {
 
743
        bytes_written =::write(m_fd, m_ascii_buffer, fmt_buf_bytes);
 
744
      }
 
745
 
 
746
      if (bytes_written < 0) {
 
747
        Error("An error was encountered in writing to %s: %s.", ((m_name) ? m_name : "logfile"), strerror(errno));
 
748
      } else {
 
749
        if (bytes_written < fmt_buf_bytes) {
 
750
          m_overspill_bytes = fmt_buf_bytes - bytes_written;
 
751
          memcpy(m_overspill_buffer, &m_ascii_buffer[bytes_written], m_overspill_bytes);
 
752
          m_overspill_written = 0;
 
753
        }
 
754
        total_bytes += bytes_written;
 
755
      }
 
756
    }
 
757
  }
 
758
  return total_bytes;
 
759
}
 
760
 
 
761
/*-------------------------------------------------------------------------
 
762
  LogFile::writeln
 
763
 
 
764
  This function will make sure the following data is written to the
 
765
  output file (m_fd) with a trailing newline.
 
766
  -------------------------------------------------------------------------*/
 
767
 
 
768
int
 
769
LogFile::writeln(char *data, int len, int fd, const char *path)
 
770
{
 
771
  int total_bytes = 0;
 
772
 
 
773
  if (len > 0 && data && fd >= 0) {
 
774
    struct iovec wvec[2];
 
775
    memset(&wvec, 0, sizeof(iovec));
 
776
    memset(&wvec[1], 0, sizeof(iovec));
 
777
    int bytes_this_write, vcnt = 1;
 
778
 
 
779
#if defined(solaris)
 
780
    wvec[0].iov_base = (caddr_t) data;
 
781
#else
 
782
    wvec[0].iov_base = (void *) data;
 
783
#endif
 
784
    wvec[0].iov_len = (size_t) len;
 
785
 
 
786
    if (data[len - 1] != '\n') {
 
787
#if defined(solaris)
 
788
      wvec[1].iov_base = (caddr_t) "\n";
 
789
#else
 
790
      wvec[1].iov_base = (void *) "\n";
 
791
#endif
 
792
      wvec[1].iov_len = (size_t) 1;
 
793
      vcnt++;
 
794
    }
 
795
 
 
796
    if ((bytes_this_write = (int)::writev(fd, (const struct iovec *) wvec, vcnt)) < 0) {
 
797
      Warning("An error was encountered in writing to %s: %s.", ((path) ? path : "logfile"), strerror(errno));
 
798
    } else
 
799
      total_bytes = bytes_this_write;
 
800
  }
 
801
  return total_bytes;
 
802
}
 
803
 
 
804
/*-------------------------------------------------------------------------
 
805
  LogFile::check_fd
 
806
 
 
807
  This routine will occasionally stat the current logfile to make sure that
 
808
  it really does exist.  The easiest way to do this is to close the file
 
809
  and re-open it, which will create the file if it doesn't already exist.
 
810
 
 
811
  Failure to open the logfile will generate a manager alarm and a Warning.
 
812
  -------------------------------------------------------------------------*/
 
813
 
 
814
void
 
815
LogFile::check_fd()
 
816
{
 
817
  static bool failure_last_call = false;
 
818
  static unsigned stat_check_count = 1;
 
819
 
 
820
  if ((stat_check_count % Log::config->file_stat_frequency) == 0) {
 
821
    //
 
822
    // It's time to see if the file really exists.  If we can't see
 
823
    // the file (via access), then we'll close our descriptor and
 
824
    // attept to re-open it, which will create the file if it's not
 
825
    // there.
 
826
    //
 
827
    if (m_name && !LogFile::exists(m_name)) {
 
828
      close_file();
 
829
    }
 
830
    stat_check_count = 0;
 
831
  }
 
832
  stat_check_count++;
 
833
 
 
834
  int err = open_file();
 
835
  if (err != LOG_FILE_NO_ERROR && err != LOG_FILE_NO_PIPE_READERS) {
 
836
    if (!failure_last_call) {
 
837
      LogUtils::manager_alarm(LogUtils::LOG_ALARM_ERROR, "Traffic Server could not open logfile %s.", m_name);
 
838
      Warning("Traffic Server could not open logfile %s: %s.", m_name, strerror(errno));
 
839
    }
 
840
    failure_last_call = true;
 
841
    return;
 
842
  }
 
843
 
 
844
  failure_last_call = false;
 
845
}
 
846
 
 
847
void
 
848
LogFile::display(FILE * fd)
 
849
{
 
850
  fprintf(fd, "Logfile: %s, %s\n", get_name(), (is_open())? "file is open" : "file is not open");
 
851
}
 
852
 
 
853
int
 
854
LogFile::do_filesystem_checks()
 
855
{
 
856
  int ret_val = 0;
 
857
 
 
858
  int e = LogUtils::file_is_writeable(m_name, &m_size_bytes,
 
859
                                      &m_has_size_limit,
 
860
                                      &m_size_limit_bytes);
 
861
 
 
862
  if (e == 1) {
 
863
    Error("Log file %s is not a regular file or pipe", m_name);
 
864
    ret_val = -1;
 
865
  } else if (e == -1) {
 
866
    Error("Filesystem checks for log file %s failed: %s", m_name, strerror(errno));
 
867
    ret_val = -1;
 
868
  } else if (m_has_size_limit) {
 
869
    uint64_t safe_threshold =
 
870
      (m_file_format == ASCII_PIPE ? 0 : Log::config->log_buffer_size * FILESIZE_SAFE_THRESHOLD_FACTOR);
 
871
    if (safe_threshold > m_size_limit_bytes) {
 
872
      Error("Filesize limit is too low for log file %s", m_name);
 
873
      ret_val = -1;
 
874
    } else {
 
875
      m_size_limit_bytes = m_size_limit_bytes - safe_threshold;
 
876
    }
 
877
  }
 
878
 
 
879
  m_filesystem_checks_done = true;
 
880
  return ret_val;
 
881
}
 
882
 
 
883
/***************************************************************************
 
884
 LogFileList IS NOT USED
 
885
****************************************************************************/
 
886
 
 
887
 
 
888
/****************************************************************************
 
889
 
 
890
  MetaInfo methods
 
891
 
 
892
*****************************************************************************/
 
893
 
 
894
void
 
895
MetaInfo::_build_name(const char *filename)
 
896
{
 
897
  int i = -1, l = 0;
 
898
  char c;
 
899
  while (c = filename[l], c != 0) {
 
900
    if (c == '/') {
 
901
      i = l;
 
902
    }
 
903
    ++l;
 
904
  }
 
905
 
 
906
  // 7 = 1 (dot at beginning) + 5 (".meta") + 1 (null terminating)
 
907
  //
 
908
  _filename = (char *) xmalloc(l + 7);
 
909
 
 
910
  if (i < 0) {
 
911
    ink_string_concatenate_strings(_filename, ".", filename, ".meta", NULL);
 
912
  } else {
 
913
    memcpy(_filename, filename, i + 1);
 
914
    ink_string_concatenate_strings(&_filename[i + 1], ".", &filename[i + 1]
 
915
                                   , ".meta", NULL);
 
916
  }
 
917
}
 
918
 
 
919
void
 
920
MetaInfo::_read_from_file()
 
921
{
 
922
  _flags |= DATA_FROM_METAFILE;
 
923
  int fd = open(_filename, O_RDONLY);
 
924
  if (fd <= 0) {
 
925
    Warning("Could not open metafile %s for reading: %s", _filename, strerror(errno));
 
926
  } else {
 
927
    _flags |= FILE_OPEN_SUCCESSFUL;
 
928
    SimpleTokenizer tok('=', SimpleTokenizer::OVERWRITE_INPUT_STRING);
 
929
    int line_number = 1;
 
930
    while (ink_file_fd_readline(fd, BUF_SIZE, _buffer) > 0) {
 
931
      tok.setString(_buffer);
 
932
      char *t = tok.getNext();
 
933
      if (t) {
 
934
        if (strcmp(t, "creation_time") == 0) {
 
935
          t = tok.getNext();
 
936
          if (t) {
 
937
            _creation_time = (time_t) ink_atoi64(t);
 
938
            _flags |= VALID_CREATION_TIME;
 
939
          }
 
940
        } else if (strcmp(t, "object_signature") == 0) {
 
941
          t = tok.getNext();
 
942
          if (t) {
 
943
            _log_object_signature = ink_atoi64(t);
 
944
            _flags |= VALID_SIGNATURE;
 
945
            Debug("log-meta", "MetaInfo::_read_from_file\n"
 
946
                  "\tfilename = %s\n"
 
947
                  "\tsignature string = %s\n" "\tsignature value = %" PRIu64 "", _filename, t, _log_object_signature);
 
948
          }
 
949
        } else if (line_number == 1) {
 
950
          _creation_time = (time_t) atol(t);
 
951
          _flags |= PRE_PANDA_METAFILE | VALID_CREATION_TIME;
 
952
        }
 
953
      }
 
954
      ++line_number;
 
955
    }
 
956
    close(fd);
 
957
  }
 
958
}
 
959
 
 
960
void
 
961
MetaInfo::_write_to_file()
 
962
{
 
963
  int fd = open(_filename, O_WRONLY | O_CREAT | O_TRUNC,
 
964
                Log::config->logfile_perm);
 
965
 
 
966
  if (fd <= 0) {
 
967
    Warning("Could not open metafile %s for writing: %s", _filename, strerror(errno));
 
968
  } else {
 
969
    int n;
 
970
    if (_flags & VALID_CREATION_TIME) {
 
971
      n = snprintf(_buffer, BUF_SIZE, "creation_time = %lu\n", (unsigned long) _creation_time);
 
972
      // TODO modify this runtime check so that it is not an assertion
 
973
      ink_release_assert(n <= BUF_SIZE);
 
974
      if (write(fd, _buffer, n) == -1) {
 
975
        Warning("Could not write creation_time");
 
976
      }
 
977
    }
 
978
    if (_flags & VALID_SIGNATURE) {
 
979
      n = snprintf(_buffer, BUF_SIZE, "object_signature = %" PRIu64 "\n", _log_object_signature);
 
980
      // TODO modify this runtime check so that it is not an assertion
 
981
      ink_release_assert(n <= BUF_SIZE);
 
982
      if (write(fd, _buffer, n) == -1) {
 
983
        Warning("Could not write object_signaure");
 
984
      }
 
985
      Debug("log-meta", "MetaInfo::_write_to_file\n"
 
986
            "\tfilename = %s\n"
 
987
            "\tsignature value = %" PRIu64 "\n" "\tsignature string = %s", _filename, _log_object_signature, _buffer);
 
988
    }
 
989
  }
 
990
  close(fd);
 
991
}