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"
31 #include "string-stream.h"
32
33 namespace v8 {
34 namespace internal {
35
36 #ifdef ENABLE_LOGGING_AND_PROFILING
37
LogDynamicBuffer(int block_size,int max_size,const char * seal,int seal_size)38 LogDynamicBuffer::LogDynamicBuffer(
39 int block_size, int max_size, const char* seal, int seal_size)
40 : block_size_(block_size),
41 max_size_(max_size - (max_size % block_size_)),
42 seal_(seal),
43 seal_size_(seal_size),
44 blocks_(max_size_ / block_size_ + 1),
45 write_pos_(0), block_index_(0), block_write_pos_(0), is_sealed_(false) {
46 ASSERT(BlocksCount() > 0);
47 AllocateBlock(0);
48 for (int i = 1; i < BlocksCount(); ++i) {
49 blocks_[i] = NULL;
50 }
51 }
52
53
~LogDynamicBuffer()54 LogDynamicBuffer::~LogDynamicBuffer() {
55 for (int i = 0; i < BlocksCount(); ++i) {
56 DeleteArray(blocks_[i]);
57 }
58 }
59
60
Read(int from_pos,char * dest_buf,int buf_size)61 int LogDynamicBuffer::Read(int from_pos, char* dest_buf, int buf_size) {
62 if (buf_size == 0) return 0;
63 int read_pos = from_pos;
64 int block_read_index = BlockIndex(from_pos);
65 int block_read_pos = PosInBlock(from_pos);
66 int dest_buf_pos = 0;
67 // Read until dest_buf is filled, or write_pos_ encountered.
68 while (read_pos < write_pos_ && dest_buf_pos < buf_size) {
69 const int read_size = Min(write_pos_ - read_pos,
70 Min(buf_size - dest_buf_pos, block_size_ - block_read_pos));
71 memcpy(dest_buf + dest_buf_pos,
72 blocks_[block_read_index] + block_read_pos, read_size);
73 block_read_pos += read_size;
74 dest_buf_pos += read_size;
75 read_pos += read_size;
76 if (block_read_pos == block_size_) {
77 block_read_pos = 0;
78 ++block_read_index;
79 }
80 }
81 return dest_buf_pos;
82 }
83
84
Seal()85 int LogDynamicBuffer::Seal() {
86 WriteInternal(seal_, seal_size_);
87 is_sealed_ = true;
88 return 0;
89 }
90
91
Write(const char * data,int data_size)92 int LogDynamicBuffer::Write(const char* data, int data_size) {
93 if (is_sealed_) {
94 return 0;
95 }
96 if ((write_pos_ + data_size) <= (max_size_ - seal_size_)) {
97 return WriteInternal(data, data_size);
98 } else {
99 return Seal();
100 }
101 }
102
103
WriteInternal(const char * data,int data_size)104 int LogDynamicBuffer::WriteInternal(const char* data, int data_size) {
105 int data_pos = 0;
106 while (data_pos < data_size) {
107 const int write_size =
108 Min(data_size - data_pos, block_size_ - block_write_pos_);
109 memcpy(blocks_[block_index_] + block_write_pos_, data + data_pos,
110 write_size);
111 block_write_pos_ += write_size;
112 data_pos += write_size;
113 if (block_write_pos_ == block_size_) {
114 block_write_pos_ = 0;
115 AllocateBlock(++block_index_);
116 }
117 }
118 write_pos_ += data_size;
119 return data_size;
120 }
121
122 // Must be the same message as in Logger::PauseProfiler.
123 const char* const Log::kDynamicBufferSeal = "profiler,\"pause\"\n";
124
Log(Logger * logger)125 Log::Log(Logger* logger)
126 : write_to_file_(false),
127 is_stopped_(false),
128 output_handle_(NULL),
129 output_code_handle_(NULL),
130 output_buffer_(NULL),
131 mutex_(NULL),
132 message_buffer_(NULL),
133 logger_(logger) {
134 }
135
136
AddIsolateIdIfNeeded(StringStream * stream)137 static void AddIsolateIdIfNeeded(StringStream* stream) {
138 Isolate* isolate = Isolate::Current();
139 if (isolate->IsDefaultIsolate()) return;
140 stream->Add("isolate-%p-", isolate);
141 }
142
143
Initialize()144 void Log::Initialize() {
145 #ifdef ENABLE_LOGGING_AND_PROFILING
146 mutex_ = OS::CreateMutex();
147 message_buffer_ = NewArray<char>(kMessageBufferSize);
148
149 // --log-all enables all the log flags.
150 if (FLAG_log_all) {
151 FLAG_log_runtime = true;
152 FLAG_log_api = true;
153 FLAG_log_code = true;
154 FLAG_log_gc = true;
155 FLAG_log_suspect = true;
156 FLAG_log_handles = true;
157 FLAG_log_regexp = true;
158 }
159
160 // --prof implies --log-code.
161 if (FLAG_prof) FLAG_log_code = true;
162
163 // --prof_lazy controls --log-code, implies --noprof_auto.
164 if (FLAG_prof_lazy) {
165 FLAG_log_code = false;
166 FLAG_prof_auto = false;
167 }
168
169 bool start_logging = FLAG_log || FLAG_log_runtime || FLAG_log_api
170 || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect
171 || FLAG_log_regexp || FLAG_log_state_changes;
172
173 bool open_log_file = start_logging || FLAG_prof_lazy;
174
175 // If we're logging anything, we need to open the log file.
176 if (open_log_file) {
177 if (strcmp(FLAG_logfile, "-") == 0) {
178 OpenStdout();
179 } else if (strcmp(FLAG_logfile, "*") == 0) {
180 OpenMemoryBuffer();
181 } else {
182 if (strchr(FLAG_logfile, '%') != NULL ||
183 !Isolate::Current()->IsDefaultIsolate()) {
184 // If there's a '%' in the log file name we have to expand
185 // placeholders.
186 HeapStringAllocator allocator;
187 StringStream stream(&allocator);
188 AddIsolateIdIfNeeded(&stream);
189 for (const char* p = FLAG_logfile; *p; p++) {
190 if (*p == '%') {
191 p++;
192 switch (*p) {
193 case '\0':
194 // If there's a % at the end of the string we back up
195 // one character so we can escape the loop properly.
196 p--;
197 break;
198 case 't': {
199 // %t expands to the current time in milliseconds.
200 double time = OS::TimeCurrentMillis();
201 stream.Add("%.0f", FmtElm(time));
202 break;
203 }
204 case '%':
205 // %% expands (contracts really) to %.
206 stream.Put('%');
207 break;
208 default:
209 // All other %'s expand to themselves.
210 stream.Put('%');
211 stream.Put(*p);
212 break;
213 }
214 } else {
215 stream.Put(*p);
216 }
217 }
218 SmartPointer<const char> expanded = stream.ToCString();
219 OpenFile(*expanded);
220 } else {
221 OpenFile(FLAG_logfile);
222 }
223 }
224 }
225 #endif
226 }
227
228
OpenStdout()229 void Log::OpenStdout() {
230 ASSERT(!IsEnabled());
231 output_handle_ = stdout;
232 write_to_file_ = true;
233 }
234
235
236 static const char kCodeLogExt[] = ".code";
237
238
OpenFile(const char * name)239 void Log::OpenFile(const char* name) {
240 ASSERT(!IsEnabled());
241 output_handle_ = OS::FOpen(name, OS::LogFileOpenMode);
242 write_to_file_ = true;
243 if (FLAG_ll_prof) {
244 // Open a file for logging the contents of code objects so that
245 // they can be disassembled later.
246 size_t name_len = strlen(name);
247 ScopedVector<char> code_name(
248 static_cast<int>(name_len + sizeof(kCodeLogExt)));
249 memcpy(code_name.start(), name, name_len);
250 memcpy(code_name.start() + name_len, kCodeLogExt, sizeof(kCodeLogExt));
251 output_code_handle_ = OS::FOpen(code_name.start(), OS::LogFileOpenMode);
252 }
253 }
254
255
OpenMemoryBuffer()256 void Log::OpenMemoryBuffer() {
257 ASSERT(!IsEnabled());
258 output_buffer_ = new LogDynamicBuffer(
259 kDynamicBufferBlockSize, kMaxDynamicBufferSize,
260 kDynamicBufferSeal, StrLength(kDynamicBufferSeal));
261 write_to_file_ = false;
262 }
263
264
Close()265 void Log::Close() {
266 if (write_to_file_) {
267 if (output_handle_ != NULL) fclose(output_handle_);
268 output_handle_ = NULL;
269 if (output_code_handle_ != NULL) fclose(output_code_handle_);
270 output_code_handle_ = NULL;
271 } else {
272 delete output_buffer_;
273 output_buffer_ = NULL;
274 }
275
276 DeleteArray(message_buffer_);
277 message_buffer_ = NULL;
278
279 delete mutex_;
280 mutex_ = NULL;
281
282 is_stopped_ = false;
283 }
284
285
GetLogLines(int from_pos,char * dest_buf,int max_size)286 int Log::GetLogLines(int from_pos, char* dest_buf, int max_size) {
287 if (write_to_file_) return 0;
288 ASSERT(output_buffer_ != NULL);
289 ASSERT(from_pos >= 0);
290 ASSERT(max_size >= 0);
291 int actual_size = output_buffer_->Read(from_pos, dest_buf, max_size);
292 ASSERT(actual_size <= max_size);
293 if (actual_size == 0) return 0;
294
295 // Find previous log line boundary.
296 char* end_pos = dest_buf + actual_size - 1;
297 while (end_pos >= dest_buf && *end_pos != '\n') --end_pos;
298 actual_size = static_cast<int>(end_pos - dest_buf + 1);
299 // If the assertion below is hit, it means that there was no line end
300 // found --- something wrong has happened.
301 ASSERT(actual_size > 0);
302 ASSERT(actual_size <= max_size);
303 return actual_size;
304 }
305
306
LogMessageBuilder(Logger * logger)307 LogMessageBuilder::LogMessageBuilder(Logger* logger)
308 : log_(logger->log_),
309 sl(log_->mutex_),
310 pos_(0) {
311 ASSERT(log_->message_buffer_ != NULL);
312 }
313
314
Append(const char * format,...)315 void LogMessageBuilder::Append(const char* format, ...) {
316 Vector<char> buf(log_->message_buffer_ + pos_,
317 Log::kMessageBufferSize - pos_);
318 va_list args;
319 va_start(args, format);
320 AppendVA(format, args);
321 va_end(args);
322 ASSERT(pos_ <= Log::kMessageBufferSize);
323 }
324
325
AppendVA(const char * format,va_list args)326 void LogMessageBuilder::AppendVA(const char* format, va_list args) {
327 Vector<char> buf(log_->message_buffer_ + pos_,
328 Log::kMessageBufferSize - pos_);
329 int result = v8::internal::OS::VSNPrintF(buf, format, args);
330
331 // Result is -1 if output was truncated.
332 if (result >= 0) {
333 pos_ += result;
334 } else {
335 pos_ = Log::kMessageBufferSize;
336 }
337 ASSERT(pos_ <= Log::kMessageBufferSize);
338 }
339
340
Append(const char c)341 void LogMessageBuilder::Append(const char c) {
342 if (pos_ < Log::kMessageBufferSize) {
343 log_->message_buffer_[pos_++] = c;
344 }
345 ASSERT(pos_ <= Log::kMessageBufferSize);
346 }
347
348
Append(String * str)349 void LogMessageBuilder::Append(String* str) {
350 AssertNoAllocation no_heap_allocation; // Ensure string stay valid.
351 int length = str->length();
352 for (int i = 0; i < length; i++) {
353 Append(static_cast<char>(str->Get(i)));
354 }
355 }
356
357
AppendAddress(Address addr)358 void LogMessageBuilder::AppendAddress(Address addr) {
359 Append("0x%" V8PRIxPTR, addr);
360 }
361
362
AppendDetailed(String * str,bool show_impl_info)363 void LogMessageBuilder::AppendDetailed(String* str, bool show_impl_info) {
364 AssertNoAllocation no_heap_allocation; // Ensure string stay valid.
365 int len = str->length();
366 if (len > 0x1000)
367 len = 0x1000;
368 if (show_impl_info) {
369 Append(str->IsAsciiRepresentation() ? 'a' : '2');
370 if (StringShape(str).IsExternal())
371 Append('e');
372 if (StringShape(str).IsSymbol())
373 Append('#');
374 Append(":%i:", str->length());
375 }
376 for (int i = 0; i < len; i++) {
377 uc32 c = str->Get(i);
378 if (c > 0xff) {
379 Append("\\u%04x", c);
380 } else if (c < 32 || c > 126) {
381 Append("\\x%02x", c);
382 } else if (c == ',') {
383 Append("\\,");
384 } else if (c == '\\') {
385 Append("\\\\");
386 } else if (c == '\"') {
387 Append("\"\"");
388 } else {
389 Append("%lc", c);
390 }
391 }
392 }
393
394
AppendStringPart(const char * str,int len)395 void LogMessageBuilder::AppendStringPart(const char* str, int len) {
396 if (pos_ + len > Log::kMessageBufferSize) {
397 len = Log::kMessageBufferSize - pos_;
398 ASSERT(len >= 0);
399 if (len == 0) return;
400 }
401 Vector<char> buf(log_->message_buffer_ + pos_,
402 Log::kMessageBufferSize - pos_);
403 OS::StrNCpy(buf, str, len);
404 pos_ += len;
405 ASSERT(pos_ <= Log::kMessageBufferSize);
406 }
407
408
WriteToLogFile()409 void LogMessageBuilder::WriteToLogFile() {
410 ASSERT(pos_ <= Log::kMessageBufferSize);
411 const int written = log_->write_to_file_ ?
412 log_->WriteToFile(log_->message_buffer_, pos_) :
413 log_->WriteToMemory(log_->message_buffer_, pos_);
414 if (written != pos_) {
415 log_->stop();
416 log_->logger_->LogFailure();
417 }
418 }
419
420
421 #endif // ENABLE_LOGGING_AND_PROFILING
422
423 } } // namespace v8::internal
424