• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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