sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 1 | // Copyright 2009 the V8 project authors. All rights reserved. |
| 2 | // Redistribution and use in source and binary forms, with or without |
| 3 | // modification, are permitted provided that the following conditions are |
| 4 | // met: |
| 5 | // |
| 6 | // * Redistributions of source code must retain the above copyright |
| 7 | // notice, this list of conditions and the following disclaimer. |
| 8 | // * Redistributions in binary form must reproduce the above |
| 9 | // copyright notice, this list of conditions and the following |
| 10 | // disclaimer in the documentation and/or other materials provided |
| 11 | // with the distribution. |
| 12 | // * Neither the name of Google Inc. nor the names of its |
| 13 | // contributors may be used to endorse or promote products derived |
| 14 | // from this software without specific prior written permission. |
| 15 | // |
| 16 | // THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS |
| 17 | // "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT |
| 18 | // LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR |
| 19 | // A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT |
| 20 | // OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, |
| 21 | // SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT |
| 22 | // LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, |
| 23 | // DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY |
| 24 | // THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT |
| 25 | // (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE |
| 26 | // OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. |
| 27 | |
| 28 | #include "v8.h" |
| 29 | |
| 30 | #include "log-utils.h" |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 31 | #include "string-stream.h" |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 32 | |
| 33 | namespace v8 { |
| 34 | namespace internal { |
| 35 | |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 36 | |
whesse@chromium.org | 030d38e | 2011-07-13 13:23:34 +0000 | [diff] [blame^] | 37 | const char* Log::kLogToTemporaryFile = "&"; |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 38 | |
| 39 | |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 40 | Log::Log(Logger* logger) |
whesse@chromium.org | 030d38e | 2011-07-13 13:23:34 +0000 | [diff] [blame^] | 41 | : is_stopped_(false), |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 42 | output_handle_(NULL), |
sgjesse@chromium.org | 8e8294a | 2011-05-02 14:30:53 +0000 | [diff] [blame] | 43 | ll_output_handle_(NULL), |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 44 | mutex_(NULL), |
| 45 | message_buffer_(NULL), |
| 46 | logger_(logger) { |
| 47 | } |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 48 | |
| 49 | |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 50 | static void AddIsolateIdIfNeeded(StringStream* stream) { |
| 51 | Isolate* isolate = Isolate::Current(); |
| 52 | if (isolate->IsDefaultIsolate()) return; |
| 53 | stream->Add("isolate-%p-", isolate); |
| 54 | } |
| 55 | |
| 56 | |
| 57 | void Log::Initialize() { |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 58 | mutex_ = OS::CreateMutex(); |
| 59 | message_buffer_ = NewArray<char>(kMessageBufferSize); |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 60 | |
| 61 | // --log-all enables all the log flags. |
| 62 | if (FLAG_log_all) { |
| 63 | FLAG_log_runtime = true; |
| 64 | FLAG_log_api = true; |
| 65 | FLAG_log_code = true; |
| 66 | FLAG_log_gc = true; |
| 67 | FLAG_log_suspect = true; |
| 68 | FLAG_log_handles = true; |
| 69 | FLAG_log_regexp = true; |
| 70 | } |
| 71 | |
| 72 | // --prof implies --log-code. |
| 73 | if (FLAG_prof) FLAG_log_code = true; |
| 74 | |
| 75 | // --prof_lazy controls --log-code, implies --noprof_auto. |
| 76 | if (FLAG_prof_lazy) { |
| 77 | FLAG_log_code = false; |
| 78 | FLAG_prof_auto = false; |
| 79 | } |
| 80 | |
whesse@chromium.org | 030d38e | 2011-07-13 13:23:34 +0000 | [diff] [blame^] | 81 | bool open_log_file = FLAG_log || FLAG_log_runtime || FLAG_log_api |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 82 | || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect |
sgjesse@chromium.org | 8e8294a | 2011-05-02 14:30:53 +0000 | [diff] [blame] | 83 | || FLAG_log_regexp || FLAG_log_state_changes || FLAG_ll_prof; |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 84 | |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 85 | // If we're logging anything, we need to open the log file. |
| 86 | if (open_log_file) { |
| 87 | if (strcmp(FLAG_logfile, "-") == 0) { |
| 88 | OpenStdout(); |
| 89 | } else if (strcmp(FLAG_logfile, "*") == 0) { |
whesse@chromium.org | 030d38e | 2011-07-13 13:23:34 +0000 | [diff] [blame^] | 90 | // Does nothing for now. Will be removed. |
| 91 | } else if (strcmp(FLAG_logfile, kLogToTemporaryFile) == 0) { |
| 92 | OpenTemporaryFile(); |
| 93 | } else { |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 94 | if (strchr(FLAG_logfile, '%') != NULL || |
| 95 | !Isolate::Current()->IsDefaultIsolate()) { |
| 96 | // If there's a '%' in the log file name we have to expand |
| 97 | // placeholders. |
| 98 | HeapStringAllocator allocator; |
| 99 | StringStream stream(&allocator); |
| 100 | AddIsolateIdIfNeeded(&stream); |
| 101 | for (const char* p = FLAG_logfile; *p; p++) { |
| 102 | if (*p == '%') { |
| 103 | p++; |
| 104 | switch (*p) { |
| 105 | case '\0': |
| 106 | // If there's a % at the end of the string we back up |
| 107 | // one character so we can escape the loop properly. |
| 108 | p--; |
| 109 | break; |
| 110 | case 't': { |
| 111 | // %t expands to the current time in milliseconds. |
| 112 | double time = OS::TimeCurrentMillis(); |
| 113 | stream.Add("%.0f", FmtElm(time)); |
| 114 | break; |
| 115 | } |
| 116 | case '%': |
| 117 | // %% expands (contracts really) to %. |
| 118 | stream.Put('%'); |
| 119 | break; |
| 120 | default: |
| 121 | // All other %'s expand to themselves. |
| 122 | stream.Put('%'); |
| 123 | stream.Put(*p); |
| 124 | break; |
| 125 | } |
| 126 | } else { |
| 127 | stream.Put(*p); |
| 128 | } |
| 129 | } |
| 130 | SmartPointer<const char> expanded = stream.ToCString(); |
| 131 | OpenFile(*expanded); |
| 132 | } else { |
| 133 | OpenFile(FLAG_logfile); |
| 134 | } |
| 135 | } |
| 136 | } |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 137 | } |
| 138 | |
| 139 | |
| 140 | void Log::OpenStdout() { |
| 141 | ASSERT(!IsEnabled()); |
| 142 | output_handle_ = stdout; |
whesse@chromium.org | 030d38e | 2011-07-13 13:23:34 +0000 | [diff] [blame^] | 143 | } |
| 144 | |
| 145 | |
| 146 | void Log::OpenTemporaryFile() { |
| 147 | ASSERT(!IsEnabled()); |
| 148 | output_handle_ = i::OS::OpenTemporaryFile(); |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 149 | } |
| 150 | |
| 151 | |
sgjesse@chromium.org | 8e8294a | 2011-05-02 14:30:53 +0000 | [diff] [blame] | 152 | // Extension added to V8 log file name to get the low-level log name. |
| 153 | static const char kLowLevelLogExt[] = ".ll"; |
| 154 | |
| 155 | // File buffer size of the low-level log. We don't use the default to |
| 156 | // minimize the associated overhead. |
| 157 | static const int kLowLevelLogBufferSize = 2 * MB; |
whesse@chromium.org | 4a5224e | 2010-10-20 12:37:07 +0000 | [diff] [blame] | 158 | |
| 159 | |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 160 | void Log::OpenFile(const char* name) { |
| 161 | ASSERT(!IsEnabled()); |
| 162 | output_handle_ = OS::FOpen(name, OS::LogFileOpenMode); |
whesse@chromium.org | 4a5224e | 2010-10-20 12:37:07 +0000 | [diff] [blame] | 163 | if (FLAG_ll_prof) { |
sgjesse@chromium.org | 8e8294a | 2011-05-02 14:30:53 +0000 | [diff] [blame] | 164 | // Open the low-level log file. |
| 165 | size_t len = strlen(name); |
| 166 | ScopedVector<char> ll_name(static_cast<int>(len + sizeof(kLowLevelLogExt))); |
| 167 | memcpy(ll_name.start(), name, len); |
| 168 | memcpy(ll_name.start() + len, kLowLevelLogExt, sizeof(kLowLevelLogExt)); |
| 169 | ll_output_handle_ = OS::FOpen(ll_name.start(), OS::LogFileOpenMode); |
| 170 | setvbuf(ll_output_handle_, NULL, _IOFBF, kLowLevelLogBufferSize); |
whesse@chromium.org | 4a5224e | 2010-10-20 12:37:07 +0000 | [diff] [blame] | 171 | } |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 172 | } |
| 173 | |
| 174 | |
whesse@chromium.org | 030d38e | 2011-07-13 13:23:34 +0000 | [diff] [blame^] | 175 | FILE* Log::Close() { |
| 176 | FILE* result = NULL; |
| 177 | if (output_handle_ != NULL) { |
| 178 | if (strcmp(FLAG_logfile, kLogToTemporaryFile) != 0) { |
| 179 | fclose(output_handle_); |
| 180 | } else { |
| 181 | result = output_handle_; |
| 182 | } |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 183 | } |
whesse@chromium.org | 030d38e | 2011-07-13 13:23:34 +0000 | [diff] [blame^] | 184 | output_handle_ = NULL; |
| 185 | if (ll_output_handle_ != NULL) fclose(ll_output_handle_); |
| 186 | ll_output_handle_ = NULL; |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 187 | |
ager@chromium.org | eadaf22 | 2009-06-16 09:43:10 +0000 | [diff] [blame] | 188 | DeleteArray(message_buffer_); |
| 189 | message_buffer_ = NULL; |
| 190 | |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 191 | delete mutex_; |
| 192 | mutex_ = NULL; |
| 193 | |
| 194 | is_stopped_ = false; |
whesse@chromium.org | 030d38e | 2011-07-13 13:23:34 +0000 | [diff] [blame^] | 195 | return result; |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 196 | } |
| 197 | |
| 198 | |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 199 | LogMessageBuilder::LogMessageBuilder(Logger* logger) |
| 200 | : log_(logger->log_), |
| 201 | sl(log_->mutex_), |
| 202 | pos_(0) { |
| 203 | ASSERT(log_->message_buffer_ != NULL); |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 204 | } |
| 205 | |
| 206 | |
| 207 | void LogMessageBuilder::Append(const char* format, ...) { |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 208 | Vector<char> buf(log_->message_buffer_ + pos_, |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 209 | Log::kMessageBufferSize - pos_); |
| 210 | va_list args; |
| 211 | va_start(args, format); |
ager@chromium.org | eadaf22 | 2009-06-16 09:43:10 +0000 | [diff] [blame] | 212 | AppendVA(format, args); |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 213 | va_end(args); |
| 214 | ASSERT(pos_ <= Log::kMessageBufferSize); |
| 215 | } |
| 216 | |
| 217 | |
ager@chromium.org | eadaf22 | 2009-06-16 09:43:10 +0000 | [diff] [blame] | 218 | void LogMessageBuilder::AppendVA(const char* format, va_list args) { |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 219 | Vector<char> buf(log_->message_buffer_ + pos_, |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 220 | Log::kMessageBufferSize - pos_); |
| 221 | int result = v8::internal::OS::VSNPrintF(buf, format, args); |
| 222 | |
| 223 | // Result is -1 if output was truncated. |
| 224 | if (result >= 0) { |
| 225 | pos_ += result; |
| 226 | } else { |
| 227 | pos_ = Log::kMessageBufferSize; |
| 228 | } |
| 229 | ASSERT(pos_ <= Log::kMessageBufferSize); |
| 230 | } |
| 231 | |
| 232 | |
| 233 | void LogMessageBuilder::Append(const char c) { |
| 234 | if (pos_ < Log::kMessageBufferSize) { |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 235 | log_->message_buffer_[pos_++] = c; |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 236 | } |
| 237 | ASSERT(pos_ <= Log::kMessageBufferSize); |
| 238 | } |
| 239 | |
| 240 | |
| 241 | void LogMessageBuilder::Append(String* str) { |
| 242 | AssertNoAllocation no_heap_allocation; // Ensure string stay valid. |
| 243 | int length = str->length(); |
| 244 | for (int i = 0; i < length; i++) { |
| 245 | Append(static_cast<char>(str->Get(i))); |
| 246 | } |
| 247 | } |
| 248 | |
| 249 | |
ager@chromium.org | eadaf22 | 2009-06-16 09:43:10 +0000 | [diff] [blame] | 250 | void LogMessageBuilder::AppendAddress(Address addr) { |
ager@chromium.org | 5f0c45f | 2010-12-17 08:51:21 +0000 | [diff] [blame] | 251 | Append("0x%" V8PRIxPTR, addr); |
ager@chromium.org | eadaf22 | 2009-06-16 09:43:10 +0000 | [diff] [blame] | 252 | } |
| 253 | |
| 254 | |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 255 | void LogMessageBuilder::AppendDetailed(String* str, bool show_impl_info) { |
sgjesse@chromium.org | 8e8294a | 2011-05-02 14:30:53 +0000 | [diff] [blame] | 256 | if (str == NULL) return; |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 257 | AssertNoAllocation no_heap_allocation; // Ensure string stay valid. |
| 258 | int len = str->length(); |
| 259 | if (len > 0x1000) |
| 260 | len = 0x1000; |
| 261 | if (show_impl_info) { |
| 262 | Append(str->IsAsciiRepresentation() ? 'a' : '2'); |
| 263 | if (StringShape(str).IsExternal()) |
| 264 | Append('e'); |
| 265 | if (StringShape(str).IsSymbol()) |
| 266 | Append('#'); |
| 267 | Append(":%i:", str->length()); |
| 268 | } |
| 269 | for (int i = 0; i < len; i++) { |
| 270 | uc32 c = str->Get(i); |
| 271 | if (c > 0xff) { |
| 272 | Append("\\u%04x", c); |
| 273 | } else if (c < 32 || c > 126) { |
| 274 | Append("\\x%02x", c); |
| 275 | } else if (c == ',') { |
| 276 | Append("\\,"); |
| 277 | } else if (c == '\\') { |
| 278 | Append("\\\\"); |
fschneider@chromium.org | 3a5fd78 | 2011-02-24 10:10:44 +0000 | [diff] [blame] | 279 | } else if (c == '\"') { |
| 280 | Append("\"\""); |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 281 | } else { |
| 282 | Append("%lc", c); |
| 283 | } |
| 284 | } |
| 285 | } |
| 286 | |
| 287 | |
christian.plesner.hansen@gmail.com | 2bc58ef | 2009-09-22 10:00:30 +0000 | [diff] [blame] | 288 | void LogMessageBuilder::AppendStringPart(const char* str, int len) { |
| 289 | if (pos_ + len > Log::kMessageBufferSize) { |
| 290 | len = Log::kMessageBufferSize - pos_; |
| 291 | ASSERT(len >= 0); |
| 292 | if (len == 0) return; |
| 293 | } |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 294 | Vector<char> buf(log_->message_buffer_ + pos_, |
christian.plesner.hansen@gmail.com | 2bc58ef | 2009-09-22 10:00:30 +0000 | [diff] [blame] | 295 | Log::kMessageBufferSize - pos_); |
| 296 | OS::StrNCpy(buf, str, len); |
| 297 | pos_ += len; |
| 298 | ASSERT(pos_ <= Log::kMessageBufferSize); |
| 299 | } |
| 300 | |
| 301 | |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 302 | void LogMessageBuilder::WriteToLogFile() { |
| 303 | ASSERT(pos_ <= Log::kMessageBufferSize); |
whesse@chromium.org | 030d38e | 2011-07-13 13:23:34 +0000 | [diff] [blame^] | 304 | const int written = log_->WriteToFile(log_->message_buffer_, pos_); |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 305 | if (written != pos_) { |
| 306 | log_->stop(); |
| 307 | log_->logger_->LogFailure(); |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 308 | } |
| 309 | } |
| 310 | |
sgjesse@chromium.org | ea88ce9 | 2011-03-23 11:19:56 +0000 | [diff] [blame] | 311 | |
sgjesse@chromium.org | 755c5b1 | 2009-05-29 11:04:38 +0000 | [diff] [blame] | 312 | } } // namespace v8::internal |