log-utils.cc 8.84 KB
Newer Older
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30
// Copyright 2009 the V8 project authors. All rights reserved.
// Redistribution and use in source and binary forms, with or without
// modification, are permitted provided that the following conditions are
// met:
//
//     * Redistributions of source code must retain the above copyright
//       notice, this list of conditions and the following disclaimer.
//     * Redistributions in binary form must reproduce the above
//       copyright notice, this list of conditions and the following
//       disclaimer in the documentation and/or other materials provided
//       with the distribution.
//     * Neither the name of Google Inc. nor the names of its
//       contributors may be used to endorse or promote products derived
//       from this software without specific prior written permission.
//
// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.

#include "v8.h"

#include "log-utils.h"
31
#include "string-stream.h"
32 33 34 35

namespace v8 {
namespace internal {

36

37
const char* const Log::kLogToTemporaryFile = "&";
38

39 40

Log::Log(Logger* logger)
41
  : is_stopped_(false),
42
    output_handle_(NULL),
43
    ll_output_handle_(NULL),
44 45 46 47 48 49 50 51 52 53 54
    mutex_(NULL),
    message_buffer_(NULL),
    logger_(logger) {
}


static void AddIsolateIdIfNeeded(StringStream* stream) {
  Isolate* isolate = Isolate::Current();
  if (isolate->IsDefaultIsolate()) return;
  stream->Add("isolate-%p-", isolate);
}
55 56


57
void Log::Initialize() {
58 59
  mutex_ = OS::CreateMutex();
  message_buffer_ = NewArray<char>(kMessageBufferSize);
60 61 62 63 64 65 66 67 68 69

  // --log-all enables all the log flags.
  if (FLAG_log_all) {
    FLAG_log_runtime = true;
    FLAG_log_api = true;
    FLAG_log_code = true;
    FLAG_log_gc = true;
    FLAG_log_suspect = true;
    FLAG_log_handles = true;
    FLAG_log_regexp = true;
70
    FLAG_log_internal_timer_events = true;
71 72 73 74 75 76 77 78 79 80 81
  }

  // --prof implies --log-code.
  if (FLAG_prof) FLAG_log_code = true;

  // --prof_lazy controls --log-code, implies --noprof_auto.
  if (FLAG_prof_lazy) {
    FLAG_log_code = false;
    FLAG_prof_auto = false;
  }

82
  bool open_log_file = FLAG_log || FLAG_log_runtime || FLAG_log_api
83
      || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect
84
      || FLAG_log_regexp || FLAG_log_state_changes || FLAG_ll_prof
85
      || FLAG_log_internal_timer_events;
86 87 88 89 90

  // If we're logging anything, we need to open the log file.
  if (open_log_file) {
    if (strcmp(FLAG_logfile, "-") == 0) {
      OpenStdout();
91 92 93
    } else if (strcmp(FLAG_logfile, kLogToTemporaryFile) == 0) {
      OpenTemporaryFile();
    } else {
94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129
      if (strchr(FLAG_logfile, '%') != NULL ||
          !Isolate::Current()->IsDefaultIsolate()) {
        // If there's a '%' in the log file name we have to expand
        // placeholders.
        HeapStringAllocator allocator;
        StringStream stream(&allocator);
        AddIsolateIdIfNeeded(&stream);
        for (const char* p = FLAG_logfile; *p; p++) {
          if (*p == '%') {
            p++;
            switch (*p) {
              case '\0':
                // If there's a % at the end of the string we back up
                // one character so we can escape the loop properly.
                p--;
                break;
              case 't': {
                // %t expands to the current time in milliseconds.
                double time = OS::TimeCurrentMillis();
                stream.Add("%.0f", FmtElm(time));
                break;
              }
              case '%':
                // %% expands (contracts really) to %.
                stream.Put('%');
                break;
              default:
                // All other %'s expand to themselves.
                stream.Put('%');
                stream.Put(*p);
                break;
            }
          } else {
            stream.Put(*p);
          }
        }
130
        SmartArrayPointer<const char> expanded = stream.ToCString();
131 132 133 134 135 136
        OpenFile(*expanded);
      } else {
        OpenFile(FLAG_logfile);
      }
    }
  }
137 138 139 140 141 142
}


void Log::OpenStdout() {
  ASSERT(!IsEnabled());
  output_handle_ = stdout;
143 144 145 146 147 148
}


void Log::OpenTemporaryFile() {
  ASSERT(!IsEnabled());
  output_handle_ = i::OS::OpenTemporaryFile();
149 150 151
}


152 153 154 155 156 157
// Extension added to V8 log file name to get the low-level log name.
static const char kLowLevelLogExt[] = ".ll";

// File buffer size of the low-level log. We don't use the default to
// minimize the associated overhead.
static const int kLowLevelLogBufferSize = 2 * MB;
158 159


160 161 162
void Log::OpenFile(const char* name) {
  ASSERT(!IsEnabled());
  output_handle_ = OS::FOpen(name, OS::LogFileOpenMode);
163
  if (FLAG_ll_prof) {
164 165 166 167 168 169 170
    // Open the low-level log file.
    size_t len = strlen(name);
    ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLowLevelLogExt)));
    memcpy(ll_name.start(), name, len);
    memcpy(ll_name.start() + len, kLowLevelLogExt, sizeof(kLowLevelLogExt));
    ll_output_handle_ = OS::FOpen(ll_name.start(), OS::LogFileOpenMode);
    setvbuf(ll_output_handle_, NULL, _IOFBF, kLowLevelLogBufferSize);
171
  }
172 173 174
}


175 176 177 178 179 180 181 182
FILE* Log::Close() {
  FILE* result = NULL;
  if (output_handle_ != NULL) {
    if (strcmp(FLAG_logfile, kLogToTemporaryFile) != 0) {
      fclose(output_handle_);
    } else {
      result = output_handle_;
    }
183
  }
184 185 186
  output_handle_ = NULL;
  if (ll_output_handle_ != NULL) fclose(ll_output_handle_);
  ll_output_handle_ = NULL;
187

188 189 190
  DeleteArray(message_buffer_);
  message_buffer_ = NULL;

191 192
  delete mutex_;
  mutex_ = NULL;
193 194

  is_stopped_ = false;
195
  return result;
196 197 198
}


199 200 201 202 203
LogMessageBuilder::LogMessageBuilder(Logger* logger)
  : log_(logger->log_),
    sl(log_->mutex_),
    pos_(0) {
  ASSERT(log_->message_buffer_ != NULL);
204 205 206 207
}


void LogMessageBuilder::Append(const char* format, ...) {
208
  Vector<char> buf(log_->message_buffer_ + pos_,
209 210 211
                   Log::kMessageBufferSize - pos_);
  va_list args;
  va_start(args, format);
212
  AppendVA(format, args);
213 214 215 216 217
  va_end(args);
  ASSERT(pos_ <= Log::kMessageBufferSize);
}


218
void LogMessageBuilder::AppendVA(const char* format, va_list args) {
219
  Vector<char> buf(log_->message_buffer_ + pos_,
220 221 222 223 224 225 226 227 228 229 230 231 232 233 234
                   Log::kMessageBufferSize - pos_);
  int result = v8::internal::OS::VSNPrintF(buf, format, args);

  // Result is -1 if output was truncated.
  if (result >= 0) {
    pos_ += result;
  } else {
    pos_ = Log::kMessageBufferSize;
  }
  ASSERT(pos_ <= Log::kMessageBufferSize);
}


void LogMessageBuilder::Append(const char c) {
  if (pos_ < Log::kMessageBufferSize) {
235
    log_->message_buffer_[pos_++] = c;
236 237 238 239 240 241 242 243 244 245 246 247 248 249
  }
  ASSERT(pos_ <= Log::kMessageBufferSize);
}


void LogMessageBuilder::Append(String* str) {
  AssertNoAllocation no_heap_allocation;  // Ensure string stay valid.
  int length = str->length();
  for (int i = 0; i < length; i++) {
    Append(static_cast<char>(str->Get(i)));
  }
}


250
void LogMessageBuilder::AppendAddress(Address addr) {
251
  Append("0x%" V8PRIxPTR, addr);
252 253 254
}


255
void LogMessageBuilder::AppendDetailed(String* str, bool show_impl_info) {
256
  if (str == NULL) return;
257 258 259 260 261
  AssertNoAllocation no_heap_allocation;  // Ensure string stay valid.
  int len = str->length();
  if (len > 0x1000)
    len = 0x1000;
  if (show_impl_info) {
262
    Append(str->IsOneByteRepresentation() ? 'a' : '2');
263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278
    if (StringShape(str).IsExternal())
      Append('e');
    if (StringShape(str).IsSymbol())
      Append('#');
    Append(":%i:", str->length());
  }
  for (int i = 0; i < len; i++) {
    uc32 c = str->Get(i);
    if (c > 0xff) {
      Append("\\u%04x", c);
    } else if (c < 32 || c > 126) {
      Append("\\x%02x", c);
    } else if (c == ',') {
      Append("\\,");
    } else if (c == '\\') {
      Append("\\\\");
279 280
    } else if (c == '\"') {
      Append("\"\"");
281 282 283 284 285 286 287
    } else {
      Append("%lc", c);
    }
  }
}


288 289 290 291 292 293
void LogMessageBuilder::AppendStringPart(const char* str, int len) {
  if (pos_ + len > Log::kMessageBufferSize) {
    len = Log::kMessageBufferSize - pos_;
    ASSERT(len >= 0);
    if (len == 0) return;
  }
294
  Vector<char> buf(log_->message_buffer_ + pos_,
295 296
                   Log::kMessageBufferSize - pos_);
  OS::StrNCpy(buf, str, len);
297 298 299 300 301
  pos_ += len;
  ASSERT(pos_ <= Log::kMessageBufferSize);
}


302 303
void LogMessageBuilder::WriteToLogFile() {
  ASSERT(pos_ <= Log::kMessageBufferSize);
304
  const int written = log_->WriteToFile(log_->message_buffer_, pos_);
305 306 307
  if (written != pos_) {
    log_->stop();
    log_->logger_->LogFailure();
308
  }
309 310
}

311

312
} }  // namespace v8::internal