blob: 2ed01415cd7f939decb0f28e606e12246b98ca5b [file] [log] [blame]
ager@chromium.orgea91cc52011-05-23 06:06:11 +00001// Copyright 2011 the V8 project authors. All rights reserved.
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00002// 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 <stdarg.h>
29
30#include "v8.h"
31
kasperl@chromium.orgf5aa8372009-03-24 14:47:14 +000032#include "bootstrapper.h"
ricow@chromium.orgd236f4d2010-09-01 06:52:08 +000033#include "code-stubs.h"
kasperl@chromium.orga5551262010-12-07 12:49:48 +000034#include "deoptimizer.h"
ager@chromium.org01beca72009-11-24 14:29:16 +000035#include "global-handles.h"
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +000036#include "log.h"
christian.plesner.hansen@gmail.com37abdec2009-01-06 14:43:28 +000037#include "macro-assembler.h"
jkummerow@chromium.org1456e702012-03-30 08:38:13 +000038#include "platform.h"
kasperl@chromium.orga5551262010-12-07 12:49:48 +000039#include "runtime-profiler.h"
kasperl@chromium.orgf5aa8372009-03-24 14:47:14 +000040#include "serialize.h"
41#include "string-stream.h"
kasperl@chromium.orga5551262010-12-07 12:49:48 +000042#include "vm-state-inl.h"
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +000043
kasperl@chromium.org71affb52009-05-26 05:44:31 +000044namespace v8 {
45namespace internal {
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +000046
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +000047// The Profiler samples pc and sp values for the main thread.
48// Each sample is appended to a circular buffer.
49// An independent thread removes data and writes it to the log.
50// This design minimizes the time spent in the sampler.
51//
52class Profiler: public Thread {
53 public:
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +000054 explicit Profiler(Isolate* isolate);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +000055 void Engage();
56 void Disengage();
57
58 // Inserts collected profiling data into buffer.
59 void Insert(TickSample* sample) {
iposva@chromium.org245aa852009-02-10 00:49:54 +000060 if (paused_)
61 return;
62
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +000063 if (Succ(head_) == tail_) {
64 overflow_ = true;
65 } else {
66 buffer_[head_] = *sample;
67 head_ = Succ(head_);
68 buffer_semaphore_->Signal(); // Tell we have an element.
69 }
70 }
71
72 // Waits for a signal and removes profiling data.
73 bool Remove(TickSample* sample) {
74 buffer_semaphore_->Wait(); // Wait for an element.
75 *sample = buffer_[tail_];
76 bool result = overflow_;
77 tail_ = Succ(tail_);
78 overflow_ = false;
79 return result;
80 }
81
82 void Run();
83
iposva@chromium.org245aa852009-02-10 00:49:54 +000084 // Pause and Resume TickSample data collection.
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +000085 bool paused() const { return paused_; }
86 void pause() { paused_ = true; }
87 void resume() { paused_ = false; }
iposva@chromium.org245aa852009-02-10 00:49:54 +000088
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +000089 private:
90 // Returns the next index in the cyclic buffer.
91 int Succ(int index) { return (index + 1) % kBufferSize; }
92
svenpanne@chromium.org6d786c92011-06-15 10:58:27 +000093 Isolate* isolate_;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +000094 // Cyclic buffer for communicating profiling samples
95 // between the signal handler and the worker thread.
96 static const int kBufferSize = 128;
97 TickSample buffer_[kBufferSize]; // Buffer storage.
98 int head_; // Index to the buffer head.
99 int tail_; // Index to the buffer tail.
100 bool overflow_; // Tell whether a buffer overflow has occurred.
101 Semaphore* buffer_semaphore_; // Sempahore used for buffer synchronization.
102
ager@chromium.org3811b432009-10-28 14:53:37 +0000103 // Tells whether profiler is engaged, that is, processing thread is stated.
104 bool engaged_;
105
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000106 // Tells whether worker thread should continue running.
107 bool running_;
iposva@chromium.org245aa852009-02-10 00:49:54 +0000108
109 // Tells whether we are currently recording tick samples.
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000110 bool paused_;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000111};
112
113
114//
kasperl@chromium.org061ef742009-02-27 12:16:20 +0000115// StackTracer implementation
116//
yangguo@chromium.org46839fb2012-08-28 09:06:19 +0000117DISABLE_ASAN void StackTracer::Trace(Isolate* isolate, TickSample* sample) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000118 ASSERT(isolate->IsInitialized());
119
kasperl@chromium.orga5551262010-12-07 12:49:48 +0000120 // Avoid collecting traces while doing GC.
lrn@chromium.org25156de2010-04-06 13:10:27 +0000121 if (sample->state == GC) return;
kasperl@chromium.org7be3c992009-03-12 07:19:55 +0000122
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000123 const Address js_entry_sp =
124 Isolate::js_entry_sp(isolate->thread_local_top());
ager@chromium.orge2902be2009-06-08 12:21:35 +0000125 if (js_entry_sp == 0) {
126 // Not executing JS now.
ager@chromium.orge2902be2009-06-08 12:21:35 +0000127 return;
128 }
129
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000130 const Address callback = isolate->external_callback();
131 if (callback != NULL) {
132 sample->external_callback = callback;
133 sample->has_external_callback = true;
134 } else {
135 // Sample potential return address value for frameless invocation of
136 // stubs (we'll figure out later, if this value makes sense).
137 sample->tos = Memory::Address_at(sample->sp);
138 sample->has_external_callback = false;
ager@chromium.org01beca72009-11-24 14:29:16 +0000139 }
140
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000141 SafeStackTraceFrameIterator it(isolate,
142 sample->fp, sample->sp,
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +0000143 sample->sp, js_entry_sp);
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000144 int i = 0;
ager@chromium.orgbb29dc92009-03-24 13:25:23 +0000145 while (!it.done() && i < TickSample::kMaxFramesCount) {
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +0000146 sample->stack[i++] = it.frame()->pc();
ager@chromium.orgbb29dc92009-03-24 13:25:23 +0000147 it.Advance();
kasperl@chromium.org061ef742009-02-27 12:16:20 +0000148 }
ager@chromium.orgbb29dc92009-03-24 13:25:23 +0000149 sample->frames_count = i;
kasperl@chromium.org061ef742009-02-27 12:16:20 +0000150}
151
152
153//
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000154// Ticker used to provide ticks to the profiler and the sliding state
155// window.
156//
mads.s.ager@gmail.com9a4089a2008-09-01 08:55:01 +0000157class Ticker: public Sampler {
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000158 public:
vegorov@chromium.org74f333b2011-04-06 11:17:46 +0000159 Ticker(Isolate* isolate, int interval):
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000160 Sampler(isolate, interval),
kasperl@chromium.orga5551262010-12-07 12:49:48 +0000161 profiler_(NULL) {}
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000162
163 ~Ticker() { if (IsActive()) Stop(); }
164
whesse@chromium.org4a5224e2010-10-20 12:37:07 +0000165 virtual void Tick(TickSample* sample) {
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000166 if (profiler_) profiler_->Insert(sample);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000167 }
168
169 void SetProfiler(Profiler* profiler) {
kasperl@chromium.orga5551262010-12-07 12:49:48 +0000170 ASSERT(profiler_ == NULL);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000171 profiler_ = profiler;
kasperl@chromium.orga5551262010-12-07 12:49:48 +0000172 IncreaseProfilingDepth();
kasperl@chromium.org71affb52009-05-26 05:44:31 +0000173 if (!FLAG_prof_lazy && !IsActive()) Start();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000174 }
175
176 void ClearProfiler() {
kasperl@chromium.orga5551262010-12-07 12:49:48 +0000177 DecreaseProfilingDepth();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000178 profiler_ = NULL;
jkummerow@chromium.org5323a9c2012-12-10 19:00:50 +0000179 if (IsActive()) Stop();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000180 }
181
ager@chromium.orgbeb25712010-11-29 08:02:25 +0000182 protected:
183 virtual void DoSampleStack(TickSample* sample) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000184 StackTracer::Trace(isolate(), sample);
ager@chromium.orgbeb25712010-11-29 08:02:25 +0000185 }
186
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000187 private:
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000188 Profiler* profiler_;
189};
190
191
192//
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000193// Profiler implementation.
194//
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000195Profiler::Profiler(Isolate* isolate)
svenpanne@chromium.org6d786c92011-06-15 10:58:27 +0000196 : Thread("v8:Profiler"),
197 isolate_(isolate),
lrn@chromium.org5d00b602011-01-05 09:51:43 +0000198 head_(0),
ager@chromium.org3811b432009-10-28 14:53:37 +0000199 tail_(0),
200 overflow_(false),
201 buffer_semaphore_(OS::CreateSemaphore(0)),
202 engaged_(false),
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000203 running_(false),
204 paused_(false) {
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000205}
206
207
208void Profiler::Engage() {
ager@chromium.org3811b432009-10-28 14:53:37 +0000209 if (engaged_) return;
210 engaged_ = true;
211
mstarzinger@chromium.org068ea0a2013-01-30 09:39:44 +0000212 OS::LogSharedLibraryAddresses();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000213
214 // Start thread processing the profiler buffer.
215 running_ = true;
216 Start();
217
218 // Register to get ticks.
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000219 LOGGER->ticker_->SetProfiler(this);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000220
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000221 LOGGER->ProfilerBeginEvent();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000222}
223
224
225void Profiler::Disengage() {
ager@chromium.org3811b432009-10-28 14:53:37 +0000226 if (!engaged_) return;
227
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000228 // Stop receiving ticks.
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000229 LOGGER->ticker_->ClearProfiler();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000230
231 // Terminate the worker thread by setting running_ to false,
232 // inserting a fake element in the queue and then wait for
233 // the thread to terminate.
234 running_ = false;
235 TickSample sample;
kasperl@chromium.org71affb52009-05-26 05:44:31 +0000236 // Reset 'paused_' flag, otherwise semaphore may not be signalled.
237 resume();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000238 Insert(&sample);
239 Join();
240
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000241 LOG(ISOLATE, UncheckedStringEvent("profiler", "end"));
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000242}
243
244
245void Profiler::Run() {
246 TickSample sample;
fschneider@chromium.org40b9da32010-06-28 11:29:21 +0000247 bool overflow = Remove(&sample);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000248 while (running_) {
svenpanne@chromium.org6d786c92011-06-15 10:58:27 +0000249 LOG(isolate_, TickEvent(&sample, overflow));
fschneider@chromium.org40b9da32010-06-28 11:29:21 +0000250 overflow = Remove(&sample);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000251 }
252}
253
254
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000255// Low-level profiling event structures.
256
257struct LowLevelCodeCreateStruct {
258 static const char kTag = 'C';
259
260 int32_t name_size;
261 Address code_address;
262 int32_t code_size;
263};
264
265
266struct LowLevelCodeMoveStruct {
267 static const char kTag = 'M';
268
269 Address from_address;
270 Address to_address;
271};
272
273
274struct LowLevelCodeDeleteStruct {
275 static const char kTag = 'D';
276
277 Address address;
278};
279
280
281struct LowLevelSnapshotPositionStruct {
282 static const char kTag = 'P';
283
284 Address address;
285 int32_t position;
286};
287
288
289static const char kCodeMovingGCTag = 'G';
290
291
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000292//
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000293// Logger class implementation.
294//
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000295
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000296class Logger::NameMap {
297 public:
298 NameMap() : impl_(&PointerEquals) {}
299
300 ~NameMap() {
301 for (HashMap::Entry* p = impl_.Start(); p != NULL; p = impl_.Next(p)) {
302 DeleteArray(static_cast<const char*>(p->value));
303 }
304 }
305
306 void Insert(Address code_address, const char* name, int name_size) {
307 HashMap::Entry* entry = FindOrCreateEntry(code_address);
308 if (entry->value == NULL) {
309 entry->value = CopyName(name, name_size);
310 }
311 }
312
313 const char* Lookup(Address code_address) {
314 HashMap::Entry* entry = FindEntry(code_address);
315 return (entry != NULL) ? static_cast<const char*>(entry->value) : NULL;
316 }
317
318 void Remove(Address code_address) {
319 HashMap::Entry* entry = FindEntry(code_address);
ager@chromium.org04921a82011-06-27 13:21:41 +0000320 if (entry != NULL) {
321 DeleteArray(static_cast<char*>(entry->value));
322 RemoveEntry(entry);
323 }
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000324 }
325
326 void Move(Address from, Address to) {
327 if (from == to) return;
328 HashMap::Entry* from_entry = FindEntry(from);
329 ASSERT(from_entry != NULL);
330 void* value = from_entry->value;
331 RemoveEntry(from_entry);
332 HashMap::Entry* to_entry = FindOrCreateEntry(to);
333 ASSERT(to_entry->value == NULL);
334 to_entry->value = value;
335 }
336
337 private:
338 static bool PointerEquals(void* lhs, void* rhs) {
339 return lhs == rhs;
340 }
341
342 static char* CopyName(const char* name, int name_size) {
343 char* result = NewArray<char>(name_size + 1);
344 for (int i = 0; i < name_size; ++i) {
345 char c = name[i];
346 if (c == '\0') c = ' ';
347 result[i] = c;
348 }
349 result[name_size] = '\0';
350 return result;
351 }
352
353 HashMap::Entry* FindOrCreateEntry(Address code_address) {
354 return impl_.Lookup(code_address, ComputePointerHash(code_address), true);
355 }
356
357 HashMap::Entry* FindEntry(Address code_address) {
358 return impl_.Lookup(code_address, ComputePointerHash(code_address), false);
359 }
360
361 void RemoveEntry(HashMap::Entry* entry) {
362 impl_.Remove(entry->key, entry->hash);
363 }
364
365 HashMap impl_;
366
367 DISALLOW_COPY_AND_ASSIGN(NameMap);
368};
369
370
371class Logger::NameBuffer {
372 public:
373 NameBuffer() { Reset(); }
374
375 void Reset() {
376 utf8_pos_ = 0;
377 }
378
379 void AppendString(String* str) {
380 if (str == NULL) return;
381 if (str->HasOnlyAsciiChars()) {
382 int utf8_length = Min(str->length(), kUtf8BufferSize - utf8_pos_);
jkummerow@chromium.org59297c72013-01-09 16:32:23 +0000383 String::WriteToFlat(str,
384 reinterpret_cast<uint8_t*>(utf8_buffer_ + utf8_pos_),
385 0,
386 utf8_length);
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000387 utf8_pos_ += utf8_length;
388 return;
389 }
yangguo@chromium.org154ff992012-03-13 08:09:54 +0000390 int uc16_length = Min(str->length(), kUtf16BufferSize);
391 String::WriteToFlat(str, utf16_buffer, 0, uc16_length);
392 int previous = unibrow::Utf16::kNoPreviousCharacter;
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000393 for (int i = 0; i < uc16_length && utf8_pos_ < kUtf8BufferSize; ++i) {
yangguo@chromium.org154ff992012-03-13 08:09:54 +0000394 uc16 c = utf16_buffer[i];
jkummerow@chromium.org59297c72013-01-09 16:32:23 +0000395 if (c <= unibrow::Utf8::kMaxOneByteChar) {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000396 utf8_buffer_[utf8_pos_++] = static_cast<char>(c);
397 } else {
yangguo@chromium.org154ff992012-03-13 08:09:54 +0000398 int char_length = unibrow::Utf8::Length(c, previous);
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000399 if (utf8_pos_ + char_length > kUtf8BufferSize) break;
yangguo@chromium.org154ff992012-03-13 08:09:54 +0000400 unibrow::Utf8::Encode(utf8_buffer_ + utf8_pos_, c, previous);
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000401 utf8_pos_ += char_length;
402 }
yangguo@chromium.org154ff992012-03-13 08:09:54 +0000403 previous = c;
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000404 }
405 }
406
407 void AppendBytes(const char* bytes, int size) {
408 size = Min(size, kUtf8BufferSize - utf8_pos_);
409 memcpy(utf8_buffer_ + utf8_pos_, bytes, size);
410 utf8_pos_ += size;
411 }
412
413 void AppendBytes(const char* bytes) {
414 AppendBytes(bytes, StrLength(bytes));
415 }
416
417 void AppendByte(char c) {
418 if (utf8_pos_ >= kUtf8BufferSize) return;
419 utf8_buffer_[utf8_pos_++] = c;
420 }
421
422 void AppendInt(int n) {
423 Vector<char> buffer(utf8_buffer_ + utf8_pos_, kUtf8BufferSize - utf8_pos_);
424 int size = OS::SNPrintF(buffer, "%d", n);
425 if (size > 0 && utf8_pos_ + size <= kUtf8BufferSize) {
426 utf8_pos_ += size;
427 }
428 }
429
430 const char* get() { return utf8_buffer_; }
431 int size() const { return utf8_pos_; }
432
433 private:
434 static const int kUtf8BufferSize = 512;
yangguo@chromium.org154ff992012-03-13 08:09:54 +0000435 static const int kUtf16BufferSize = 128;
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000436
437 int utf8_pos_;
438 char utf8_buffer_[kUtf8BufferSize];
yangguo@chromium.org154ff992012-03-13 08:09:54 +0000439 uc16 utf16_buffer[kUtf16BufferSize];
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000440};
441
442
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +0000443Logger::Logger(Isolate* isolate)
444 : isolate_(isolate),
445 ticker_(NULL),
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000446 profiler_(NULL),
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000447 log_events_(NULL),
448 logging_nesting_(0),
449 cpu_profiler_nesting_(0),
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000450 log_(new Log(this)),
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000451 name_buffer_(new NameBuffer),
452 address_to_name_map_(NULL),
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000453 is_initialized_(false),
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000454 code_event_handler_(NULL),
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000455 last_address_(NULL),
456 prev_sp_(NULL),
457 prev_function_(NULL),
458 prev_to_(NULL),
ulan@chromium.org8e8d8822012-11-23 14:36:46 +0000459 prev_code_(NULL),
460 epoch_(0) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000461}
462
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000463
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000464Logger::~Logger() {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000465 delete address_to_name_map_;
466 delete name_buffer_;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000467 delete log_;
468}
ager@chromium.orgeadaf222009-06-16 09:43:10 +0000469
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000470
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000471void Logger::IssueCodeAddedEvent(Code* code,
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +0000472 Script* script,
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000473 const char* name,
474 size_t name_len) {
475 JitCodeEvent event;
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +0000476 memset(&event, 0, sizeof(event));
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000477 event.type = JitCodeEvent::CODE_ADDED;
478 event.code_start = code->instruction_start();
479 event.code_len = code->instruction_size();
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +0000480 Handle<Script> script_handle =
481 script != NULL ? Handle<Script>(script) : Handle<Script>();
482 event.script = v8::Handle<v8::Script>(ToApi<v8::Script>(script_handle));
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000483 event.name.str = name;
484 event.name.len = name_len;
485
486 code_event_handler_(&event);
487}
488
489
490void Logger::IssueCodeMovedEvent(Address from, Address to) {
491 Code* from_code = Code::cast(HeapObject::FromAddress(from));
492
493 JitCodeEvent event;
494 event.type = JitCodeEvent::CODE_MOVED;
495 event.code_start = from_code->instruction_start();
496 event.code_len = from_code->instruction_size();
497
498 // Calculate the header size.
499 const size_t header_size =
500 from_code->instruction_start() - reinterpret_cast<byte*>(from_code);
501
502 // Calculate the new start address of the instructions.
503 event.new_code_start =
504 reinterpret_cast<byte*>(HeapObject::FromAddress(to)) + header_size;
505
506 code_event_handler_(&event);
507}
508
509
510void Logger::IssueCodeRemovedEvent(Address from) {
511 Code* from_code = Code::cast(HeapObject::FromAddress(from));
512
513 JitCodeEvent event;
514 event.type = JitCodeEvent::CODE_REMOVED;
515 event.code_start = from_code->instruction_start();
516 event.code_len = from_code->instruction_size();
517
518 code_event_handler_(&event);
519}
520
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +0000521void Logger::IssueAddCodeLinePosInfoEvent(
522 void* jit_handler_data,
523 int pc_offset,
524 int position,
525 JitCodeEvent::PositionType position_type) {
526 JitCodeEvent event;
527 memset(&event, 0, sizeof(event));
528 event.type = JitCodeEvent::CODE_ADD_LINE_POS_INFO;
529 event.user_data = jit_handler_data;
530 event.line_info.offset = pc_offset;
531 event.line_info.pos = position;
532 event.line_info.position_type = position_type;
533
534 code_event_handler_(&event);
535}
536
537void* Logger::IssueStartCodePosInfoEvent() {
538 JitCodeEvent event;
539 memset(&event, 0, sizeof(event));
540 event.type = JitCodeEvent::CODE_START_LINE_INFO_RECORDING;
541
542 code_event_handler_(&event);
543 return event.user_data;
544}
545
546void Logger::IssueEndCodePosInfoEvent(Code* code, void* jit_handler_data) {
547 JitCodeEvent event;
548 memset(&event, 0, sizeof(event));
549 event.type = JitCodeEvent::CODE_END_LINE_INFO_RECORDING;
550 event.code_start = code->instruction_start();
551 event.user_data = jit_handler_data;
552
553 code_event_handler_(&event);
554}
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000555
ager@chromium.org5f0c45f2010-12-17 08:51:21 +0000556#define DECLARE_EVENT(ignore1, name) name,
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000557static const char* const kLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
ager@chromium.org5f0c45f2010-12-17 08:51:21 +0000558 LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)
ager@chromium.orgeadaf222009-06-16 09:43:10 +0000559};
ager@chromium.org5f0c45f2010-12-17 08:51:21 +0000560#undef DECLARE_EVENT
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000561
ager@chromium.org9085a012009-05-11 19:22:57 +0000562
sgjesse@chromium.org755c5b12009-05-29 11:04:38 +0000563void Logger::ProfilerBeginEvent() {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000564 if (!log_->IsEnabled()) return;
565 LogMessageBuilder msg(this);
sgjesse@chromium.org755c5b12009-05-29 11:04:38 +0000566 msg.Append("profiler,\"begin\",%d\n", kSamplingIntervalMs);
567 msg.WriteToLogFile();
568}
569
ager@chromium.org381abbb2009-02-25 13:23:22 +0000570
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000571void Logger::StringEvent(const char* name, const char* value) {
ager@chromium.org6f10e412009-02-13 10:11:16 +0000572 if (FLAG_log) UncheckedStringEvent(name, value);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000573}
574
575
ager@chromium.org6f10e412009-02-13 10:11:16 +0000576void Logger::UncheckedStringEvent(const char* name, const char* value) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000577 if (!log_->IsEnabled()) return;
578 LogMessageBuilder msg(this);
ager@chromium.org381abbb2009-02-25 13:23:22 +0000579 msg.Append("%s,\"%s\"\n", name, value);
580 msg.WriteToLogFile();
ager@chromium.org6f10e412009-02-13 10:11:16 +0000581}
ager@chromium.org6f10e412009-02-13 10:11:16 +0000582
583
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000584void Logger::IntEvent(const char* name, int value) {
ager@chromium.orgce5e87b2010-03-10 10:24:18 +0000585 if (FLAG_log) UncheckedIntEvent(name, value);
ager@chromium.orgce5e87b2010-03-10 10:24:18 +0000586}
587
588
kmillikin@chromium.orgf05f2912010-09-30 10:07:24 +0000589void Logger::IntPtrTEvent(const char* name, intptr_t value) {
kmillikin@chromium.orgf05f2912010-09-30 10:07:24 +0000590 if (FLAG_log) UncheckedIntPtrTEvent(name, value);
kmillikin@chromium.orgf05f2912010-09-30 10:07:24 +0000591}
592
593
ager@chromium.orgce5e87b2010-03-10 10:24:18 +0000594void Logger::UncheckedIntEvent(const char* name, int value) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000595 if (!log_->IsEnabled()) return;
596 LogMessageBuilder msg(this);
ager@chromium.org381abbb2009-02-25 13:23:22 +0000597 msg.Append("%s,%d\n", name, value);
598 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000599}
600
601
kmillikin@chromium.orgf05f2912010-09-30 10:07:24 +0000602void Logger::UncheckedIntPtrTEvent(const char* name, intptr_t value) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000603 if (!log_->IsEnabled()) return;
604 LogMessageBuilder msg(this);
kmillikin@chromium.orgf05f2912010-09-30 10:07:24 +0000605 msg.Append("%s,%" V8_PTR_PREFIX "d\n", name, value);
606 msg.WriteToLogFile();
607}
kmillikin@chromium.orgf05f2912010-09-30 10:07:24 +0000608
609
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000610void Logger::HandleEvent(const char* name, Object** location) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000611 if (!log_->IsEnabled() || !FLAG_log_handles) return;
612 LogMessageBuilder msg(this);
kasperl@chromium.orgb3284ad2009-05-18 06:12:45 +0000613 msg.Append("%s,0x%" V8PRIxPTR "\n", name, location);
ager@chromium.org381abbb2009-02-25 13:23:22 +0000614 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000615}
616
617
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000618// ApiEvent is private so all the calls come from the Logger class. It is the
ager@chromium.org9085a012009-05-11 19:22:57 +0000619// caller's responsibility to ensure that log is enabled and that
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000620// FLAG_log_api is true.
621void Logger::ApiEvent(const char* format, ...) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000622 ASSERT(log_->IsEnabled() && FLAG_log_api);
623 LogMessageBuilder msg(this);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000624 va_list ap;
625 va_start(ap, format);
ager@chromium.orgeadaf222009-06-16 09:43:10 +0000626 msg.AppendVA(format, ap);
ager@chromium.org381abbb2009-02-25 13:23:22 +0000627 va_end(ap);
628 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000629}
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000630
631
632void Logger::ApiNamedSecurityCheck(Object* key) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000633 if (!log_->IsEnabled() || !FLAG_log_api) return;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000634 if (key->IsString()) {
kmillikin@chromium.org83e16822011-09-13 08:21:47 +0000635 SmartArrayPointer<char> str =
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000636 String::cast(key)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
637 ApiEvent("api,check-security,\"%s\"\n", *str);
638 } else if (key->IsUndefined()) {
639 ApiEvent("api,check-security,undefined\n");
640 } else {
641 ApiEvent("api,check-security,['no-name']\n");
642 }
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000643}
644
645
646void Logger::SharedLibraryEvent(const char* library_path,
ager@chromium.org5aa501c2009-06-23 07:57:28 +0000647 uintptr_t start,
648 uintptr_t end) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000649 if (!log_->IsEnabled() || !FLAG_prof) return;
650 LogMessageBuilder msg(this);
ager@chromium.org5aa501c2009-06-23 07:57:28 +0000651 msg.Append("shared-library,\"%s\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n",
652 library_path,
653 start,
654 end);
ager@chromium.org381abbb2009-02-25 13:23:22 +0000655 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000656}
657
658
659void Logger::SharedLibraryEvent(const wchar_t* library_path,
ager@chromium.org5aa501c2009-06-23 07:57:28 +0000660 uintptr_t start,
661 uintptr_t end) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000662 if (!log_->IsEnabled() || !FLAG_prof) return;
663 LogMessageBuilder msg(this);
ager@chromium.org5aa501c2009-06-23 07:57:28 +0000664 msg.Append("shared-library,\"%ls\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n",
665 library_path,
666 start,
667 end);
ager@chromium.org381abbb2009-02-25 13:23:22 +0000668 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000669}
670
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000671
mstarzinger@chromium.org068ea0a2013-01-30 09:39:44 +0000672void Logger::TimerEvent(StartEnd se, const char* name) {
danno@chromium.org1f34ad32012-11-26 14:53:56 +0000673 if (!log_->IsEnabled()) return;
mstarzinger@chromium.org32280cf2012-12-06 17:32:37 +0000674 ASSERT(FLAG_log_internal_timer_events);
ulan@chromium.org8e8d8822012-11-23 14:36:46 +0000675 LogMessageBuilder msg(this);
mstarzinger@chromium.org068ea0a2013-01-30 09:39:44 +0000676 int since_epoch = static_cast<int>(OS::Ticks() - epoch_);
677 const char* format = (se == START) ? "timer-event-start,\"%s\",%ld\n"
678 : "timer-event-end,\"%s\",%ld\n";
679 msg.Append(format, name, since_epoch);
ulan@chromium.org8e8d8822012-11-23 14:36:46 +0000680 msg.WriteToLogFile();
681}
682
683
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +0000684void Logger::EnterExternal() {
mstarzinger@chromium.org068ea0a2013-01-30 09:39:44 +0000685 LOG(ISOLATE, TimerEvent(START, TimerEventScope::v8_external));
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +0000686}
687
688
689void Logger::LeaveExternal() {
mstarzinger@chromium.org068ea0a2013-01-30 09:39:44 +0000690 LOG(ISOLATE, TimerEvent(END, TimerEventScope::v8_external));
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +0000691}
692
693
mstarzinger@chromium.org068ea0a2013-01-30 09:39:44 +0000694void Logger::TimerEventScope::LogTimerEvent(StartEnd se) {
695 LOG(isolate_, TimerEvent(se, name_));
danno@chromium.org1f34ad32012-11-26 14:53:56 +0000696}
697
698
ulan@chromium.org8e8d8822012-11-23 14:36:46 +0000699const char* Logger::TimerEventScope::v8_recompile_synchronous =
700 "V8.RecompileSynchronous";
701const char* Logger::TimerEventScope::v8_recompile_parallel =
702 "V8.RecompileParallel";
703const char* Logger::TimerEventScope::v8_compile_full_code =
704 "V8.CompileFullCode";
705const char* Logger::TimerEventScope::v8_execute = "V8.Execute";
mstarzinger@chromium.org068ea0a2013-01-30 09:39:44 +0000706const char* Logger::TimerEventScope::v8_external = "V8.External";
ulan@chromium.org8e8d8822012-11-23 14:36:46 +0000707
708
ager@chromium.org236ad962008-09-25 09:45:57 +0000709void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000710 // Prints "/" + re.source + "/" +
711 // (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"")
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000712 LogMessageBuilder msg(this);
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000713
714 Handle<Object> source = GetProperty(regexp, "source");
715 if (!source->IsString()) {
ager@chromium.org381abbb2009-02-25 13:23:22 +0000716 msg.Append("no source");
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000717 return;
718 }
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000719
kasperl@chromium.org9fe21c62008-10-28 08:53:51 +0000720 switch (regexp->TypeTag()) {
kasperl@chromium.org41044eb2008-10-06 08:24:46 +0000721 case JSRegExp::ATOM:
ager@chromium.org381abbb2009-02-25 13:23:22 +0000722 msg.Append('a');
kasperl@chromium.org41044eb2008-10-06 08:24:46 +0000723 break;
724 default:
725 break;
kasperl@chromium.org41044eb2008-10-06 08:24:46 +0000726 }
ager@chromium.org381abbb2009-02-25 13:23:22 +0000727 msg.Append('/');
728 msg.AppendDetailed(*Handle<String>::cast(source), false);
729 msg.Append('/');
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000730
731 // global flag
732 Handle<Object> global = GetProperty(regexp, "global");
733 if (global->IsTrue()) {
ager@chromium.org381abbb2009-02-25 13:23:22 +0000734 msg.Append('g');
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000735 }
736 // ignorecase flag
737 Handle<Object> ignorecase = GetProperty(regexp, "ignoreCase");
738 if (ignorecase->IsTrue()) {
ager@chromium.org381abbb2009-02-25 13:23:22 +0000739 msg.Append('i');
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000740 }
741 // multiline flag
742 Handle<Object> multiline = GetProperty(regexp, "multiline");
743 if (multiline->IsTrue()) {
ager@chromium.org381abbb2009-02-25 13:23:22 +0000744 msg.Append('m');
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000745 }
ager@chromium.org381abbb2009-02-25 13:23:22 +0000746
747 msg.WriteToLogFile();
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000748}
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000749
750
kasperl@chromium.org9fe21c62008-10-28 08:53:51 +0000751void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000752 if (!log_->IsEnabled() || !FLAG_log_regexp) return;
753 LogMessageBuilder msg(this);
ager@chromium.org381abbb2009-02-25 13:23:22 +0000754 msg.Append("regexp-compile,");
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000755 LogRegExpSource(regexp);
ager@chromium.org381abbb2009-02-25 13:23:22 +0000756 msg.Append(in_cache ? ",hit\n" : ",miss\n");
757 msg.WriteToLogFile();
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000758}
759
760
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +0000761void Logger::LogRuntime(Isolate* isolate,
762 Vector<const char> format,
763 JSArray* args) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000764 if (!log_->IsEnabled() || !FLAG_log_runtime) return;
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +0000765 HandleScope scope(isolate);
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000766 LogMessageBuilder msg(this);
christian.plesner.hansen@gmail.com37abdec2009-01-06 14:43:28 +0000767 for (int i = 0; i < format.length(); i++) {
768 char c = format[i];
769 if (c == '%' && i <= format.length() - 2) {
770 i++;
771 ASSERT('0' <= format[i] && format[i] <= '9');
lrn@chromium.org303ada72010-10-27 09:33:13 +0000772 MaybeObject* maybe = args->GetElement(format[i] - '0');
773 Object* obj;
774 if (!maybe->ToObject(&obj)) {
775 msg.Append("<exception>");
776 continue;
777 }
christian.plesner.hansen@gmail.com37abdec2009-01-06 14:43:28 +0000778 i++;
779 switch (format[i]) {
780 case 's':
ager@chromium.org381abbb2009-02-25 13:23:22 +0000781 msg.AppendDetailed(String::cast(obj), false);
christian.plesner.hansen@gmail.com37abdec2009-01-06 14:43:28 +0000782 break;
783 case 'S':
ager@chromium.org381abbb2009-02-25 13:23:22 +0000784 msg.AppendDetailed(String::cast(obj), true);
christian.plesner.hansen@gmail.com37abdec2009-01-06 14:43:28 +0000785 break;
786 case 'r':
787 Logger::LogRegExpSource(Handle<JSRegExp>(JSRegExp::cast(obj)));
788 break;
789 case 'x':
ager@chromium.org381abbb2009-02-25 13:23:22 +0000790 msg.Append("0x%x", Smi::cast(obj)->value());
christian.plesner.hansen@gmail.com37abdec2009-01-06 14:43:28 +0000791 break;
792 case 'i':
ager@chromium.org381abbb2009-02-25 13:23:22 +0000793 msg.Append("%i", Smi::cast(obj)->value());
christian.plesner.hansen@gmail.com37abdec2009-01-06 14:43:28 +0000794 break;
795 default:
796 UNREACHABLE();
797 }
798 } else {
ager@chromium.org381abbb2009-02-25 13:23:22 +0000799 msg.Append(c);
christian.plesner.hansen@gmail.com37abdec2009-01-06 14:43:28 +0000800 }
801 }
ager@chromium.org381abbb2009-02-25 13:23:22 +0000802 msg.Append('\n');
803 msg.WriteToLogFile();
kasperl@chromium.orgb9123622008-09-17 14:05:56 +0000804}
805
806
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000807void Logger::ApiIndexedSecurityCheck(uint32_t index) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000808 if (!log_->IsEnabled() || !FLAG_log_api) return;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000809 ApiEvent("api,check-security,%u\n", index);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000810}
811
812
813void Logger::ApiNamedPropertyAccess(const char* tag,
814 JSObject* holder,
815 Object* name) {
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000816 ASSERT(name->IsString());
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000817 if (!log_->IsEnabled() || !FLAG_log_api) return;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000818 String* class_name_obj = holder->class_name();
kmillikin@chromium.org83e16822011-09-13 08:21:47 +0000819 SmartArrayPointer<char> class_name =
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000820 class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
kmillikin@chromium.org83e16822011-09-13 08:21:47 +0000821 SmartArrayPointer<char> property_name =
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000822 String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
fschneider@chromium.org7979bbb2011-03-28 10:47:03 +0000823 ApiEvent("api,%s,\"%s\",\"%s\"\n", tag, *class_name, *property_name);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000824}
825
826void Logger::ApiIndexedPropertyAccess(const char* tag,
827 JSObject* holder,
828 uint32_t index) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000829 if (!log_->IsEnabled() || !FLAG_log_api) return;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000830 String* class_name_obj = holder->class_name();
kmillikin@chromium.org83e16822011-09-13 08:21:47 +0000831 SmartArrayPointer<char> class_name =
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000832 class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
fschneider@chromium.org7979bbb2011-03-28 10:47:03 +0000833 ApiEvent("api,%s,\"%s\",%u\n", tag, *class_name, index);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000834}
835
836void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000837 if (!log_->IsEnabled() || !FLAG_log_api) return;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000838 String* class_name_obj = object->class_name();
kmillikin@chromium.org83e16822011-09-13 08:21:47 +0000839 SmartArrayPointer<char> class_name =
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000840 class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
fschneider@chromium.org7979bbb2011-03-28 10:47:03 +0000841 ApiEvent("api,%s,\"%s\"\n", tag, *class_name);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000842}
843
844
845void Logger::ApiEntryCall(const char* name) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000846 if (!log_->IsEnabled() || !FLAG_log_api) return;
fschneider@chromium.org7979bbb2011-03-28 10:47:03 +0000847 ApiEvent("api,%s\n", name);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000848}
849
850
851void Logger::NewEvent(const char* name, void* object, size_t size) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000852 if (!log_->IsEnabled() || !FLAG_log) return;
853 LogMessageBuilder msg(this);
kasperl@chromium.orgb3284ad2009-05-18 06:12:45 +0000854 msg.Append("new,%s,0x%" V8PRIxPTR ",%u\n", name, object,
ager@chromium.org381abbb2009-02-25 13:23:22 +0000855 static_cast<unsigned int>(size));
856 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000857}
858
859
860void Logger::DeleteEvent(const char* name, void* object) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000861 if (!log_->IsEnabled() || !FLAG_log) return;
862 LogMessageBuilder msg(this);
kasperl@chromium.orgb3284ad2009-05-18 06:12:45 +0000863 msg.Append("delete,%s,0x%" V8PRIxPTR "\n", name, object);
ager@chromium.org381abbb2009-02-25 13:23:22 +0000864 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +0000865}
866
867
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000868void Logger::NewEventStatic(const char* name, void* object, size_t size) {
869 LOGGER->NewEvent(name, object, size);
870}
871
872
873void Logger::DeleteEventStatic(const char* name, void* object) {
874 LOGGER->DeleteEvent(name, object);
875}
876
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +0000877void Logger::CallbackEventInternal(const char* prefix, const char* name,
878 Address entry_point) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000879 if (!log_->IsEnabled() || !FLAG_log_code) return;
880 LogMessageBuilder msg(this);
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +0000881 msg.Append("%s,%s,-3,",
ager@chromium.org5f0c45f2010-12-17 08:51:21 +0000882 kLogEventsNames[CODE_CREATION_EVENT],
883 kLogEventsNames[CALLBACK_TAG]);
ager@chromium.org01beca72009-11-24 14:29:16 +0000884 msg.AppendAddress(entry_point);
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +0000885 msg.Append(",1,\"%s%s\"", prefix, name);
ager@chromium.org01beca72009-11-24 14:29:16 +0000886 msg.Append('\n');
887 msg.WriteToLogFile();
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +0000888}
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +0000889
890
891void Logger::CallbackEvent(String* name, Address entry_point) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000892 if (!log_->IsEnabled() || !FLAG_log_code) return;
kmillikin@chromium.org83e16822011-09-13 08:21:47 +0000893 SmartArrayPointer<char> str =
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +0000894 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
895 CallbackEventInternal("", *str, entry_point);
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +0000896}
897
898
899void Logger::GetterCallbackEvent(String* name, Address entry_point) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000900 if (!log_->IsEnabled() || !FLAG_log_code) return;
kmillikin@chromium.org83e16822011-09-13 08:21:47 +0000901 SmartArrayPointer<char> str =
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +0000902 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
903 CallbackEventInternal("get ", *str, entry_point);
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +0000904}
905
906
907void Logger::SetterCallbackEvent(String* name, Address entry_point) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000908 if (!log_->IsEnabled() || !FLAG_log_code) return;
kmillikin@chromium.org83e16822011-09-13 08:21:47 +0000909 SmartArrayPointer<char> str =
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +0000910 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
911 CallbackEventInternal("set ", *str, entry_point);
ager@chromium.org01beca72009-11-24 14:29:16 +0000912}
913
914
ager@chromium.org5aa501c2009-06-23 07:57:28 +0000915void Logger::CodeCreateEvent(LogEventsAndTags tag,
916 Code* code,
917 const char* comment) {
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000918 if (!is_logging_code_events()) return;
919 if (FLAG_ll_prof || Serializer::enabled() || code_event_handler_ != NULL) {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000920 name_buffer_->Reset();
921 name_buffer_->AppendBytes(kLogEventsNames[tag]);
922 name_buffer_->AppendByte(':');
923 name_buffer_->AppendBytes(comment);
924 }
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000925 if (code_event_handler_ != NULL) {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +0000926 IssueCodeAddedEvent(code, NULL, name_buffer_->get(), name_buffer_->size());
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000927 }
928 if (!log_->IsEnabled()) return;
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000929 if (FLAG_ll_prof) {
930 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
931 }
932 if (Serializer::enabled()) {
933 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
934 }
935 if (!FLAG_log_code) return;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +0000936 LogMessageBuilder msg(this);
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +0000937 msg.Append("%s,%s,%d,",
ager@chromium.org5f0c45f2010-12-17 08:51:21 +0000938 kLogEventsNames[CODE_CREATION_EVENT],
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +0000939 kLogEventsNames[tag],
940 code->kind());
ager@chromium.org5aa501c2009-06-23 07:57:28 +0000941 msg.AppendAddress(code->address());
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +0000942 msg.Append(",%d,\"", code->ExecutableSize());
ager@chromium.org5aa501c2009-06-23 07:57:28 +0000943 for (const char* p = comment; *p != '\0'; p++) {
944 if (*p == '"') {
945 msg.Append('\\');
946 }
947 msg.Append(*p);
948 }
949 msg.Append('"');
ager@chromium.org5aa501c2009-06-23 07:57:28 +0000950 msg.Append('\n');
951 msg.WriteToLogFile();
ager@chromium.org5aa501c2009-06-23 07:57:28 +0000952}
953
954
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +0000955void Logger::CodeCreateEvent(LogEventsAndTags tag,
956 Code* code,
957 String* name) {
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000958 if (!is_logging_code_events()) return;
959 if (FLAG_ll_prof || Serializer::enabled() || code_event_handler_ != NULL) {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000960 name_buffer_->Reset();
961 name_buffer_->AppendBytes(kLogEventsNames[tag]);
962 name_buffer_->AppendByte(':');
963 name_buffer_->AppendString(name);
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +0000964 }
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000965 if (code_event_handler_ != NULL) {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +0000966 IssueCodeAddedEvent(code, NULL, name_buffer_->get(), name_buffer_->size());
yangguo@chromium.org355cfd12012-08-29 15:32:24 +0000967 }
968 if (!log_->IsEnabled()) return;
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000969 if (FLAG_ll_prof) {
970 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
971 }
972 if (Serializer::enabled()) {
973 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
974 }
975 if (!FLAG_log_code) return;
976 LogMessageBuilder msg(this);
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +0000977 msg.Append("%s,%s,%d,",
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000978 kLogEventsNames[CODE_CREATION_EVENT],
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +0000979 kLogEventsNames[tag],
980 code->kind());
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +0000981 msg.AppendAddress(code->address());
982 msg.Append(",%d,\"", code->ExecutableSize());
983 msg.AppendDetailed(name, false);
984 msg.Append('"');
985 msg.Append('\n');
986 msg.WriteToLogFile();
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +0000987}
988
989
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +0000990// ComputeMarker must only be used when SharedFunctionInfo is known.
991static const char* ComputeMarker(Code* code) {
992 switch (code->kind()) {
993 case Code::FUNCTION: return code->optimizable() ? "~" : "";
994 case Code::OPTIMIZED_FUNCTION: return "*";
995 default: return "";
996 }
997}
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +0000998
999
1000void Logger::CodeCreateEvent(LogEventsAndTags tag,
1001 Code* code,
1002 SharedFunctionInfo* shared,
1003 String* name) {
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001004 if (!is_logging_code_events()) return;
1005 if (FLAG_ll_prof || Serializer::enabled() || code_event_handler_ != NULL) {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001006 name_buffer_->Reset();
1007 name_buffer_->AppendBytes(kLogEventsNames[tag]);
1008 name_buffer_->AppendByte(':');
ager@chromium.orgea91cc52011-05-23 06:06:11 +00001009 name_buffer_->AppendBytes(ComputeMarker(code));
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001010 name_buffer_->AppendString(name);
1011 }
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001012 if (code_event_handler_ != NULL) {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001013 Script* script =
1014 shared->script()->IsScript() ? Script::cast(shared->script()) : NULL;
1015 IssueCodeAddedEvent(code,
1016 script,
1017 name_buffer_->get(),
1018 name_buffer_->size());
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001019 }
1020 if (!log_->IsEnabled()) return;
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001021 if (FLAG_ll_prof) {
1022 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
1023 }
1024 if (Serializer::enabled()) {
1025 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
1026 }
1027 if (!FLAG_log_code) return;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001028 if (code == Isolate::Current()->builtins()->builtin(
fschneider@chromium.org7979bbb2011-03-28 10:47:03 +00001029 Builtins::kLazyCompile))
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001030 return;
1031
1032 LogMessageBuilder msg(this);
kmillikin@chromium.org83e16822011-09-13 08:21:47 +00001033 SmartArrayPointer<char> str =
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001034 name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +00001035 msg.Append("%s,%s,%d,",
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001036 kLogEventsNames[CODE_CREATION_EVENT],
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +00001037 kLogEventsNames[tag],
1038 code->kind());
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001039 msg.AppendAddress(code->address());
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +00001040 msg.Append(",%d,\"%s\",", code->ExecutableSize(), *str);
1041 msg.AppendAddress(shared->address());
1042 msg.Append(",%s", ComputeMarker(code));
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001043 msg.Append('\n');
1044 msg.WriteToLogFile();
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001045}
1046
1047
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +00001048// Although, it is possible to extract source and line from
1049// the SharedFunctionInfo object, we left it to caller
1050// to leave logging functions free from heap allocations.
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001051void Logger::CodeCreateEvent(LogEventsAndTags tag,
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +00001052 Code* code,
1053 SharedFunctionInfo* shared,
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001054 String* source, int line) {
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001055 if (!is_logging_code_events()) return;
1056 if (FLAG_ll_prof || Serializer::enabled() || code_event_handler_ != NULL) {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001057 name_buffer_->Reset();
1058 name_buffer_->AppendBytes(kLogEventsNames[tag]);
1059 name_buffer_->AppendByte(':');
ager@chromium.orgea91cc52011-05-23 06:06:11 +00001060 name_buffer_->AppendBytes(ComputeMarker(code));
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001061 name_buffer_->AppendString(shared->DebugName());
1062 name_buffer_->AppendByte(' ');
1063 name_buffer_->AppendString(source);
1064 name_buffer_->AppendByte(':');
1065 name_buffer_->AppendInt(line);
1066 }
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001067 if (code_event_handler_ != NULL) {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001068 Script* script =
1069 shared->script()->IsScript() ? Script::cast(shared->script()) : NULL;
1070 IssueCodeAddedEvent(code,
1071 script,
1072 name_buffer_->get(),
1073 name_buffer_->size());
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001074 }
1075 if (!log_->IsEnabled()) return;
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001076 if (FLAG_ll_prof) {
1077 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
1078 }
1079 if (Serializer::enabled()) {
1080 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
1081 }
1082 if (!FLAG_log_code) return;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001083 LogMessageBuilder msg(this);
kmillikin@chromium.org83e16822011-09-13 08:21:47 +00001084 SmartArrayPointer<char> name =
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +00001085 shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
kmillikin@chromium.org83e16822011-09-13 08:21:47 +00001086 SmartArrayPointer<char> sourcestr =
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001087 source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +00001088 msg.Append("%s,%s,%d,",
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001089 kLogEventsNames[CODE_CREATION_EVENT],
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +00001090 kLogEventsNames[tag],
1091 code->kind());
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001092 msg.AppendAddress(code->address());
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +00001093 msg.Append(",%d,\"%s %s:%d\",",
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001094 code->ExecutableSize(),
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +00001095 *name,
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001096 *sourcestr,
1097 line);
fschneider@chromium.org3a5fd782011-02-24 10:10:44 +00001098 msg.AppendAddress(shared->address());
1099 msg.Append(",%s", ComputeMarker(code));
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001100 msg.Append('\n');
1101 msg.WriteToLogFile();
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001102}
1103
1104
1105void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count) {
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001106 if (!is_logging_code_events()) return;
1107 if (FLAG_ll_prof || Serializer::enabled() || code_event_handler_ != NULL) {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001108 name_buffer_->Reset();
1109 name_buffer_->AppendBytes(kLogEventsNames[tag]);
1110 name_buffer_->AppendByte(':');
1111 name_buffer_->AppendInt(args_count);
1112 }
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001113 if (code_event_handler_ != NULL) {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001114 IssueCodeAddedEvent(code, NULL, name_buffer_->get(), name_buffer_->size());
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001115 }
1116 if (!log_->IsEnabled()) return;
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001117 if (FLAG_ll_prof) {
1118 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
1119 }
1120 if (Serializer::enabled()) {
1121 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
1122 }
1123 if (!FLAG_log_code) return;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001124 LogMessageBuilder msg(this);
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +00001125 msg.Append("%s,%s,%d,",
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001126 kLogEventsNames[CODE_CREATION_EVENT],
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +00001127 kLogEventsNames[tag],
1128 code->kind());
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001129 msg.AppendAddress(code->address());
1130 msg.Append(",%d,\"args_count: %d\"", code->ExecutableSize(), args_count);
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001131 msg.Append('\n');
1132 msg.WriteToLogFile();
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001133}
1134
1135
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001136void Logger::CodeMovingGCEvent() {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001137 if (!log_->IsEnabled() || !FLAG_ll_prof) return;
1138 LowLevelLogWriteBytes(&kCodeMovingGCTag, sizeof(kCodeMovingGCTag));
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001139 OS::SignalCodeMovingGC();
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001140}
1141
1142
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001143void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001144 if (!is_logging_code_events()) return;
1145 if (FLAG_ll_prof || Serializer::enabled() || code_event_handler_ != NULL) {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001146 name_buffer_->Reset();
1147 name_buffer_->AppendBytes(kLogEventsNames[REG_EXP_TAG]);
1148 name_buffer_->AppendByte(':');
1149 name_buffer_->AppendString(source);
1150 }
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001151 if (code_event_handler_ != NULL) {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001152 IssueCodeAddedEvent(code, NULL, name_buffer_->get(), name_buffer_->size());
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001153 }
1154 if (!log_->IsEnabled()) return;
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001155 if (FLAG_ll_prof) {
1156 LowLevelCodeCreateEvent(code, name_buffer_->get(), name_buffer_->size());
1157 }
1158 if (Serializer::enabled()) {
1159 RegisterSnapshotCodeName(code, name_buffer_->get(), name_buffer_->size());
1160 }
1161 if (!FLAG_log_code) return;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001162 LogMessageBuilder msg(this);
svenpanne@chromium.org83130cf2012-11-30 10:13:25 +00001163 msg.Append("%s,%s,-2,",
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001164 kLogEventsNames[CODE_CREATION_EVENT],
1165 kLogEventsNames[REG_EXP_TAG]);
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001166 msg.AppendAddress(code->address());
1167 msg.Append(",%d,\"", code->ExecutableSize());
1168 msg.AppendDetailed(source, false);
1169 msg.Append('\"');
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001170 msg.Append('\n');
1171 msg.WriteToLogFile();
ager@chromium.org5aa501c2009-06-23 07:57:28 +00001172}
1173
1174
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001175void Logger::CodeMoveEvent(Address from, Address to) {
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001176 if (code_event_handler_ != NULL) IssueCodeMovedEvent(from, to);
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001177 if (!log_->IsEnabled()) return;
1178 if (FLAG_ll_prof) LowLevelCodeMoveEvent(from, to);
1179 if (Serializer::enabled() && address_to_name_map_ != NULL) {
1180 address_to_name_map_->Move(from, to);
1181 }
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001182 MoveEventInternal(CODE_MOVE_EVENT, from, to);
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001183}
1184
1185
1186void Logger::CodeDeleteEvent(Address from) {
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001187 if (code_event_handler_ != NULL) IssueCodeRemovedEvent(from);
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001188 if (!log_->IsEnabled()) return;
1189 if (FLAG_ll_prof) LowLevelCodeDeleteEvent(from);
1190 if (Serializer::enabled() && address_to_name_map_ != NULL) {
1191 address_to_name_map_->Remove(from);
1192 }
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001193 DeleteEventInternal(CODE_DELETE_EVENT, from);
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001194}
1195
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001196void Logger::CodeLinePosInfoAddPositionEvent(void* jit_handler_data,
1197 int pc_offset,
1198 int position) {
1199 if (code_event_handler_ != NULL) {
1200 IssueAddCodeLinePosInfoEvent(jit_handler_data,
1201 pc_offset,
1202 position,
1203 JitCodeEvent::POSITION);
1204 }
1205}
1206
1207void Logger::CodeLinePosInfoAddStatementPositionEvent(void* jit_handler_data,
1208 int pc_offset,
1209 int position) {
1210 if (code_event_handler_ != NULL) {
1211 IssueAddCodeLinePosInfoEvent(jit_handler_data,
1212 pc_offset,
1213 position,
1214 JitCodeEvent::STATEMENT_POSITION);
1215 }
1216}
1217
1218void Logger::CodeStartLinePosInfoRecordEvent(PositionsRecorder* pos_recorder) {
1219 if (code_event_handler_ != NULL) {
1220 pos_recorder->AttachJITHandlerData(IssueStartCodePosInfoEvent());
1221 }
1222}
1223
1224void Logger::CodeEndLinePosInfoRecordEvent(Code* code,
1225 void* jit_handler_data) {
1226 if (code_event_handler_ != NULL) {
1227 IssueEndCodePosInfoEvent(code, jit_handler_data);
1228 }
1229}
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001230
1231void Logger::SnapshotPositionEvent(Address addr, int pos) {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001232 if (!log_->IsEnabled()) return;
1233 if (FLAG_ll_prof) LowLevelSnapshotPositionEvent(addr, pos);
1234 if (Serializer::enabled() && address_to_name_map_ != NULL) {
1235 const char* code_name = address_to_name_map_->Lookup(addr);
1236 if (code_name == NULL) return; // Not a code object.
1237 LogMessageBuilder msg(this);
1238 msg.Append("%s,%d,\"", kLogEventsNames[SNAPSHOT_CODE_NAME_EVENT], pos);
1239 for (const char* p = code_name; *p != '\0'; ++p) {
1240 if (*p == '"') msg.Append('\\');
1241 msg.Append(*p);
1242 }
1243 msg.Append("\"\n");
1244 msg.WriteToLogFile();
1245 }
1246 if (!FLAG_log_snapshot_positions) return;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001247 LogMessageBuilder msg(this);
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001248 msg.Append("%s,", kLogEventsNames[SNAPSHOT_POSITION_EVENT]);
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001249 msg.AppendAddress(addr);
1250 msg.Append(",%d", pos);
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001251 msg.Append('\n');
1252 msg.WriteToLogFile();
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001253}
1254
1255
whesse@chromium.orgb08986c2011-03-14 16:13:42 +00001256void Logger::SharedFunctionInfoMoveEvent(Address from, Address to) {
whesse@chromium.orgb08986c2011-03-14 16:13:42 +00001257 MoveEventInternal(SHARED_FUNC_MOVE_EVENT, from, to);
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001258}
1259
1260
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001261void Logger::MoveEventInternal(LogEventsAndTags event,
1262 Address from,
1263 Address to) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001264 if (!log_->IsEnabled() || !FLAG_log_code) return;
1265 LogMessageBuilder msg(this);
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001266 msg.Append("%s,", kLogEventsNames[event]);
ager@chromium.orgeadaf222009-06-16 09:43:10 +00001267 msg.AppendAddress(from);
1268 msg.Append(',');
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001269 msg.AppendAddress(to);
ager@chromium.orgeadaf222009-06-16 09:43:10 +00001270 msg.Append('\n');
ager@chromium.org381abbb2009-02-25 13:23:22 +00001271 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001272}
1273
1274
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001275void Logger::DeleteEventInternal(LogEventsAndTags event, Address from) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001276 if (!log_->IsEnabled() || !FLAG_log_code) return;
1277 LogMessageBuilder msg(this);
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001278 msg.Append("%s,", kLogEventsNames[event]);
ager@chromium.orgeadaf222009-06-16 09:43:10 +00001279 msg.AppendAddress(from);
ager@chromium.orgeadaf222009-06-16 09:43:10 +00001280 msg.Append('\n');
ager@chromium.org381abbb2009-02-25 13:23:22 +00001281 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001282}
1283
1284
1285void Logger::ResourceEvent(const char* name, const char* tag) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001286 if (!log_->IsEnabled() || !FLAG_log) return;
1287 LogMessageBuilder msg(this);
ager@chromium.org381abbb2009-02-25 13:23:22 +00001288 msg.Append("%s,%s,", name, tag);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001289
1290 uint32_t sec, usec;
1291 if (OS::GetUserTime(&sec, &usec) != -1) {
ager@chromium.org381abbb2009-02-25 13:23:22 +00001292 msg.Append("%d,%d,", sec, usec);
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001293 }
ager@chromium.org381abbb2009-02-25 13:23:22 +00001294 msg.Append("%.0f", OS::TimeCurrentMillis());
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001295
ager@chromium.org381abbb2009-02-25 13:23:22 +00001296 msg.Append('\n');
1297 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001298}
1299
1300
ager@chromium.org8bb60582008-12-11 12:02:20 +00001301void Logger::SuspectReadEvent(String* name, Object* obj) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001302 if (!log_->IsEnabled() || !FLAG_log_suspect) return;
1303 LogMessageBuilder msg(this);
ager@chromium.org8bb60582008-12-11 12:02:20 +00001304 String* class_name = obj->IsJSObject()
1305 ? JSObject::cast(obj)->class_name()
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001306 : isolate_->heap()->empty_string();
ager@chromium.org381abbb2009-02-25 13:23:22 +00001307 msg.Append("suspect-read,");
1308 msg.Append(class_name);
1309 msg.Append(',');
1310 msg.Append('"');
1311 msg.Append(name);
1312 msg.Append('"');
1313 msg.Append('\n');
1314 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001315}
1316
1317
1318void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001319 if (!log_->IsEnabled() || !FLAG_log_gc) return;
1320 LogMessageBuilder msg(this);
kasperl@chromium.orge959c182009-07-27 08:59:04 +00001321 // Using non-relative system time in order to be able to synchronize with
1322 // external memory profiling events (e.g. DOM memory size).
1323 msg.Append("heap-sample-begin,\"%s\",\"%s\",%.0f\n",
1324 space, kind, OS::TimeCurrentMillis());
1325 msg.WriteToLogFile();
kasperl@chromium.orge959c182009-07-27 08:59:04 +00001326}
1327
1328
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001329void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001330 if (!log_->IsEnabled() || !FLAG_log_gc) return;
1331 LogMessageBuilder msg(this);
ager@chromium.org381abbb2009-02-25 13:23:22 +00001332 msg.Append("heap-sample-end,\"%s\",\"%s\"\n", space, kind);
1333 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001334}
1335
1336
1337void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001338 if (!log_->IsEnabled() || !FLAG_log_gc) return;
1339 LogMessageBuilder msg(this);
ager@chromium.org381abbb2009-02-25 13:23:22 +00001340 msg.Append("heap-sample-item,%s,%d,%d\n", type, number, bytes);
1341 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001342}
1343
1344
mads.s.ager@gmail.com769cc962008-08-06 10:02:49 +00001345void Logger::DebugTag(const char* call_site_tag) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001346 if (!log_->IsEnabled() || !FLAG_log) return;
1347 LogMessageBuilder msg(this);
ager@chromium.org381abbb2009-02-25 13:23:22 +00001348 msg.Append("debug-tag,%s\n", call_site_tag);
1349 msg.WriteToLogFile();
mads.s.ager@gmail.com769cc962008-08-06 10:02:49 +00001350}
1351
1352
1353void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001354 if (!log_->IsEnabled() || !FLAG_log) return;
mads.s.ager@gmail.com769cc962008-08-06 10:02:49 +00001355 StringBuilder s(parameter.length() + 1);
1356 for (int i = 0; i < parameter.length(); ++i) {
1357 s.AddCharacter(static_cast<char>(parameter[i]));
1358 }
1359 char* parameter_string = s.Finalize();
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001360 LogMessageBuilder msg(this);
ager@chromium.org381abbb2009-02-25 13:23:22 +00001361 msg.Append("debug-queue-event,%s,%15.3f,%s\n",
1362 event_type,
1363 OS::TimeCurrentMillis(),
1364 parameter_string);
mads.s.ager@gmail.com769cc962008-08-06 10:02:49 +00001365 DeleteArray(parameter_string);
ager@chromium.org381abbb2009-02-25 13:23:22 +00001366 msg.WriteToLogFile();
mads.s.ager@gmail.com769cc962008-08-06 10:02:49 +00001367}
1368
1369
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001370void Logger::TickEvent(TickSample* sample, bool overflow) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001371 if (!log_->IsEnabled() || !FLAG_prof) return;
1372 LogMessageBuilder msg(this);
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001373 msg.Append("%s,", kLogEventsNames[TICK_EVENT]);
1374 msg.AppendAddress(sample->pc);
ager@chromium.orgeadaf222009-06-16 09:43:10 +00001375 msg.Append(',');
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001376 msg.AppendAddress(sample->sp);
mstarzinger@chromium.org32280cf2012-12-06 17:32:37 +00001377 msg.Append(",%ld", static_cast<int>(OS::Ticks() - epoch_));
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001378 if (sample->has_external_callback) {
1379 msg.Append(",1,");
1380 msg.AppendAddress(sample->external_callback);
1381 } else {
1382 msg.Append(",0,");
1383 msg.AppendAddress(sample->tos);
1384 }
ager@chromium.orgeadaf222009-06-16 09:43:10 +00001385 msg.Append(",%d", static_cast<int>(sample->state));
ager@chromium.org381abbb2009-02-25 13:23:22 +00001386 if (overflow) {
1387 msg.Append(",overflow");
1388 }
kasperl@chromium.org7be3c992009-03-12 07:19:55 +00001389 for (int i = 0; i < sample->frames_count; ++i) {
ager@chromium.orgeadaf222009-06-16 09:43:10 +00001390 msg.Append(',');
ager@chromium.org5f0c45f2010-12-17 08:51:21 +00001391 msg.AppendAddress(sample->stack[i]);
ager@chromium.org381abbb2009-02-25 13:23:22 +00001392 }
1393 msg.Append('\n');
1394 msg.WriteToLogFile();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001395}
iposva@chromium.org245aa852009-02-10 00:49:54 +00001396
1397
ricow@chromium.org4f693d62011-07-04 14:01:31 +00001398bool Logger::IsProfilerPaused() {
1399 return profiler_ == NULL || profiler_->paused();
iposva@chromium.org245aa852009-02-10 00:49:54 +00001400}
1401
1402
ricow@chromium.org4f693d62011-07-04 14:01:31 +00001403void Logger::PauseProfiler() {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001404 if (!log_->IsEnabled()) return;
ricow@chromium.org4f693d62011-07-04 14:01:31 +00001405 if (profiler_ != NULL) {
ager@chromium.org5c838252010-02-19 08:53:10 +00001406 // It is OK to have negative nesting.
1407 if (--cpu_profiler_nesting_ == 0) {
1408 profiler_->pause();
1409 if (FLAG_prof_lazy) {
jkummerow@chromium.org5323a9c2012-12-10 19:00:50 +00001410 ticker_->Stop();
ager@chromium.org5c838252010-02-19 08:53:10 +00001411 FLAG_log_code = false;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001412 LOG(ISOLATE, UncheckedStringEvent("profiler", "pause"));
ager@chromium.org5c838252010-02-19 08:53:10 +00001413 }
ager@chromium.orgce5e87b2010-03-10 10:24:18 +00001414 --logging_nesting_;
sgjesse@chromium.orgb9d7da12009-08-05 08:38:10 +00001415 }
sgjesse@chromium.org755c5b12009-05-29 11:04:38 +00001416 }
iposva@chromium.org245aa852009-02-10 00:49:54 +00001417}
1418
1419
ricow@chromium.org4f693d62011-07-04 14:01:31 +00001420void Logger::ResumeProfiler() {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001421 if (!log_->IsEnabled()) return;
ricow@chromium.org4f693d62011-07-04 14:01:31 +00001422 if (profiler_ != NULL) {
ager@chromium.org5c838252010-02-19 08:53:10 +00001423 if (cpu_profiler_nesting_++ == 0) {
ager@chromium.orgce5e87b2010-03-10 10:24:18 +00001424 ++logging_nesting_;
ager@chromium.org5c838252010-02-19 08:53:10 +00001425 if (FLAG_prof_lazy) {
1426 profiler_->Engage();
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001427 LOG(ISOLATE, UncheckedStringEvent("profiler", "resume"));
ager@chromium.org5c838252010-02-19 08:53:10 +00001428 FLAG_log_code = true;
1429 LogCompiledFunctions();
ager@chromium.org5c838252010-02-19 08:53:10 +00001430 LogAccessorCallbacks();
jkummerow@chromium.org5323a9c2012-12-10 19:00:50 +00001431 if (!ticker_->IsActive()) ticker_->Start();
ager@chromium.org5c838252010-02-19 08:53:10 +00001432 }
1433 profiler_->resume();
sgjesse@chromium.orgb9d7da12009-08-05 08:38:10 +00001434 }
kasperl@chromium.org71affb52009-05-26 05:44:31 +00001435 }
iposva@chromium.org245aa852009-02-10 00:49:54 +00001436}
ager@chromium.org9085a012009-05-11 19:22:57 +00001437
1438
sgjesse@chromium.org755c5b12009-05-29 11:04:38 +00001439// This function can be called when Log's mutex is acquired,
1440// either from main or Profiler's thread.
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001441void Logger::LogFailure() {
ricow@chromium.org4f693d62011-07-04 14:01:31 +00001442 PauseProfiler();
sgjesse@chromium.org755c5b12009-05-29 11:04:38 +00001443}
1444
1445
kasperl@chromium.org71affb52009-05-26 05:44:31 +00001446bool Logger::IsProfilerSamplerActive() {
1447 return ticker_->IsActive();
1448}
1449
1450
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001451class EnumerateOptimizedFunctionsVisitor: public OptimizedFunctionVisitor {
1452 public:
1453 EnumerateOptimizedFunctionsVisitor(Handle<SharedFunctionInfo>* sfis,
1454 Handle<Code>* code_objects,
1455 int* count)
1456 : sfis_(sfis), code_objects_(code_objects), count_(count) { }
1457
1458 virtual void EnterContext(Context* context) {}
1459 virtual void LeaveContext(Context* context) {}
1460
1461 virtual void VisitFunction(JSFunction* function) {
whesse@chromium.org7b260152011-06-20 15:33:18 +00001462 SharedFunctionInfo* sfi = SharedFunctionInfo::cast(function->shared());
1463 Object* maybe_script = sfi->script();
1464 if (maybe_script->IsScript()
1465 && !Script::cast(maybe_script)->HasValidSource()) return;
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001466 if (sfis_ != NULL) {
whesse@chromium.org7b260152011-06-20 15:33:18 +00001467 sfis_[*count_] = Handle<SharedFunctionInfo>(sfi);
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001468 }
1469 if (code_objects_ != NULL) {
1470 ASSERT(function->code()->kind() == Code::OPTIMIZED_FUNCTION);
1471 code_objects_[*count_] = Handle<Code>(function->code());
1472 }
1473 *count_ = *count_ + 1;
1474 }
1475
1476 private:
1477 Handle<SharedFunctionInfo>* sfis_;
1478 Handle<Code>* code_objects_;
1479 int* count_;
1480};
1481
1482
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001483static int EnumerateCompiledFunctions(Heap* heap,
1484 Handle<SharedFunctionInfo>* sfis,
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001485 Handle<Code>* code_objects) {
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001486 HeapIterator iterator(heap);
sgjesse@chromium.org152a0b02009-10-07 13:50:16 +00001487 AssertNoAllocation no_alloc;
kasperl@chromium.org71affb52009-05-26 05:44:31 +00001488 int compiled_funcs_count = 0;
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001489
1490 // Iterate the heap to find shared function info objects and record
1491 // the unoptimized code for them.
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001492 for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
sgjesse@chromium.org152a0b02009-10-07 13:50:16 +00001493 if (!obj->IsSharedFunctionInfo()) continue;
1494 SharedFunctionInfo* sfi = SharedFunctionInfo::cast(obj);
1495 if (sfi->is_compiled()
1496 && (!sfi->script()->IsScript()
1497 || Script::cast(sfi->script())->HasValidSource())) {
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001498 if (sfis != NULL) {
sgjesse@chromium.org152a0b02009-10-07 13:50:16 +00001499 sfis[compiled_funcs_count] = Handle<SharedFunctionInfo>(sfi);
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001500 }
1501 if (code_objects != NULL) {
1502 code_objects[compiled_funcs_count] = Handle<Code>(sfi->code());
1503 }
sgjesse@chromium.org152a0b02009-10-07 13:50:16 +00001504 ++compiled_funcs_count;
kasperl@chromium.org71affb52009-05-26 05:44:31 +00001505 }
1506 }
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001507
1508 // Iterate all optimized functions in all contexts.
1509 EnumerateOptimizedFunctionsVisitor visitor(sfis,
1510 code_objects,
1511 &compiled_funcs_count);
1512 Deoptimizer::VisitAllOptimizedFunctions(&visitor);
1513
sgjesse@chromium.org152a0b02009-10-07 13:50:16 +00001514 return compiled_funcs_count;
1515}
1516
1517
ager@chromium.orgc4c92722009-11-18 14:12:51 +00001518void Logger::LogCodeObject(Object* object) {
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001519 if (FLAG_log_code || FLAG_ll_prof || is_logging_code_events()) {
ager@chromium.orgc4c92722009-11-18 14:12:51 +00001520 Code* code_object = Code::cast(object);
1521 LogEventsAndTags tag = Logger::STUB_TAG;
1522 const char* description = "Unknown code from the snapshot";
1523 switch (code_object->kind()) {
1524 case Code::FUNCTION:
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001525 case Code::OPTIMIZED_FUNCTION:
ager@chromium.orgc4c92722009-11-18 14:12:51 +00001526 return; // We log this later using LogCompiledFunctions.
danno@chromium.org40cb8782011-05-25 07:58:50 +00001527 case Code::UNARY_OP_IC: // fall through
1528 case Code::BINARY_OP_IC: // fall through
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001529 case Code::COMPARE_IC: // fall through
ricow@chromium.org9fa09672011-07-25 11:05:35 +00001530 case Code::TO_BOOLEAN_IC: // fall through
yangguo@chromium.orga6bbcc82012-12-21 12:35:02 +00001531 case Code::COMPILED_STUB: // fall through
ager@chromium.orgc4c92722009-11-18 14:12:51 +00001532 case Code::STUB:
ricow@chromium.orgd236f4d2010-09-01 06:52:08 +00001533 description =
1534 CodeStub::MajorName(CodeStub::GetMajorKey(code_object), true);
ager@chromium.org5c838252010-02-19 08:53:10 +00001535 if (description == NULL)
1536 description = "A stub from the snapshot";
ager@chromium.orgc4c92722009-11-18 14:12:51 +00001537 tag = Logger::STUB_TAG;
1538 break;
1539 case Code::BUILTIN:
1540 description = "A builtin from the snapshot";
1541 tag = Logger::BUILTIN_TAG;
1542 break;
1543 case Code::KEYED_LOAD_IC:
1544 description = "A keyed load IC from the snapshot";
1545 tag = Logger::KEYED_LOAD_IC_TAG;
1546 break;
1547 case Code::LOAD_IC:
1548 description = "A load IC from the snapshot";
1549 tag = Logger::LOAD_IC_TAG;
1550 break;
1551 case Code::STORE_IC:
1552 description = "A store IC from the snapshot";
1553 tag = Logger::STORE_IC_TAG;
1554 break;
1555 case Code::KEYED_STORE_IC:
1556 description = "A keyed store IC from the snapshot";
1557 tag = Logger::KEYED_STORE_IC_TAG;
1558 break;
1559 case Code::CALL_IC:
1560 description = "A call IC from the snapshot";
1561 tag = Logger::CALL_IC_TAG;
1562 break;
lrn@chromium.org1af7e1b2010-06-07 11:12:01 +00001563 case Code::KEYED_CALL_IC:
1564 description = "A keyed call IC from the snapshot";
1565 tag = Logger::KEYED_CALL_IC_TAG;
1566 break;
ager@chromium.orgc4c92722009-11-18 14:12:51 +00001567 }
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001568 PROFILE(ISOLATE, CodeCreateEvent(tag, code_object, description));
ager@chromium.orgc4c92722009-11-18 14:12:51 +00001569 }
1570}
1571
1572
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001573void Logger::LogCodeInfo() {
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001574 if (!log_->IsEnabled() || !FLAG_ll_prof) return;
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001575#if V8_TARGET_ARCH_IA32
1576 const char arch[] = "ia32";
1577#elif V8_TARGET_ARCH_X64
1578 const char arch[] = "x64";
1579#elif V8_TARGET_ARCH_ARM
1580 const char arch[] = "arm";
danno@chromium.orgc612e022011-11-10 11:38:15 +00001581#elif V8_TARGET_ARCH_MIPS
1582 const char arch[] = "mips";
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001583#else
1584 const char arch[] = "unknown";
1585#endif
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001586 LowLevelLogWriteBytes(arch, sizeof(arch));
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001587}
1588
1589
sgjesse@chromium.org8e8294a2011-05-02 14:30:53 +00001590void Logger::RegisterSnapshotCodeName(Code* code,
1591 const char* name,
1592 int name_size) {
1593 ASSERT(Serializer::enabled());
1594 if (address_to_name_map_ == NULL) {
1595 address_to_name_map_ = new NameMap;
1596 }
1597 address_to_name_map_->Insert(code->address(), name, name_size);
1598}
1599
1600
1601void Logger::LowLevelCodeCreateEvent(Code* code,
1602 const char* name,
1603 int name_size) {
1604 if (log_->ll_output_handle_ == NULL) return;
1605 LowLevelCodeCreateStruct event;
1606 event.name_size = name_size;
1607 event.code_address = code->instruction_start();
1608 ASSERT(event.code_address == code->address() + Code::kHeaderSize);
1609 event.code_size = code->instruction_size();
1610 LowLevelLogWriteStruct(event);
1611 LowLevelLogWriteBytes(name, name_size);
1612 LowLevelLogWriteBytes(
1613 reinterpret_cast<const char*>(code->instruction_start()),
1614 code->instruction_size());
1615}
1616
1617
1618void Logger::LowLevelCodeMoveEvent(Address from, Address to) {
1619 if (log_->ll_output_handle_ == NULL) return;
1620 LowLevelCodeMoveStruct event;
1621 event.from_address = from + Code::kHeaderSize;
1622 event.to_address = to + Code::kHeaderSize;
1623 LowLevelLogWriteStruct(event);
1624}
1625
1626
1627void Logger::LowLevelCodeDeleteEvent(Address from) {
1628 if (log_->ll_output_handle_ == NULL) return;
1629 LowLevelCodeDeleteStruct event;
1630 event.address = from + Code::kHeaderSize;
1631 LowLevelLogWriteStruct(event);
1632}
1633
1634
1635void Logger::LowLevelSnapshotPositionEvent(Address addr, int pos) {
1636 if (log_->ll_output_handle_ == NULL) return;
1637 LowLevelSnapshotPositionStruct event;
1638 event.address = addr + Code::kHeaderSize;
1639 event.position = pos;
1640 LowLevelLogWriteStruct(event);
1641}
1642
1643
1644void Logger::LowLevelLogWriteBytes(const char* bytes, int size) {
1645 size_t rv = fwrite(bytes, 1, size, log_->ll_output_handle_);
1646 ASSERT(static_cast<size_t>(size) == rv);
lrn@chromium.org303ada72010-10-27 09:33:13 +00001647 USE(rv);
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001648}
1649
1650
ager@chromium.org5c838252010-02-19 08:53:10 +00001651void Logger::LogCodeObjects() {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001652 Heap* heap = isolate_->heap();
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001653 heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
rossberg@chromium.org994edf62012-02-06 10:12:55 +00001654 "Logger::LogCodeObjects");
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001655 HeapIterator iterator(heap);
erik.corry@gmail.comc3b670f2011-10-05 21:44:48 +00001656 AssertNoAllocation no_alloc;
ager@chromium.org5c838252010-02-19 08:53:10 +00001657 for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
1658 if (obj->IsCode()) LogCodeObject(obj);
1659 }
1660}
1661
1662
lrn@chromium.org34e60782011-09-15 07:25:40 +00001663void Logger::LogExistingFunction(Handle<SharedFunctionInfo> shared,
1664 Handle<Code> code) {
1665 Handle<String> func_name(shared->DebugName());
1666 if (shared->script()->IsScript()) {
1667 Handle<Script> script(Script::cast(shared->script()));
1668 if (script->name()->IsString()) {
1669 Handle<String> script_name(String::cast(script->name()));
1670 int line_num = GetScriptLineNumber(script, shared->start_position());
1671 if (line_num > 0) {
1672 PROFILE(ISOLATE,
1673 CodeCreateEvent(
1674 Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script),
1675 *code, *shared,
1676 *script_name, line_num + 1));
1677 } else {
1678 // Can't distinguish eval and script here, so always use Script.
1679 PROFILE(ISOLATE,
1680 CodeCreateEvent(
1681 Logger::ToNativeByScript(Logger::SCRIPT_TAG, *script),
1682 *code, *shared, *script_name));
1683 }
1684 } else {
1685 PROFILE(ISOLATE,
1686 CodeCreateEvent(
1687 Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG, *script),
1688 *code, *shared, *func_name));
1689 }
1690 } else if (shared->IsApiFunction()) {
1691 // API function.
1692 FunctionTemplateInfo* fun_data = shared->get_api_func_data();
1693 Object* raw_call_data = fun_data->call_code();
1694 if (!raw_call_data->IsUndefined()) {
1695 CallHandlerInfo* call_data = CallHandlerInfo::cast(raw_call_data);
1696 Object* callback_obj = call_data->callback();
1697 Address entry_point = v8::ToCData<Address>(callback_obj);
1698 PROFILE(ISOLATE, CallbackEvent(*func_name, entry_point));
1699 }
1700 } else {
1701 PROFILE(ISOLATE,
1702 CodeCreateEvent(
1703 Logger::LAZY_COMPILE_TAG, *code, *shared, *func_name));
1704 }
1705}
1706
1707
sgjesse@chromium.org152a0b02009-10-07 13:50:16 +00001708void Logger::LogCompiledFunctions() {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001709 Heap* heap = isolate_->heap();
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001710 heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
rossberg@chromium.org994edf62012-02-06 10:12:55 +00001711 "Logger::LogCompiledFunctions");
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001712 HandleScope scope(isolate_);
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001713 const int compiled_funcs_count = EnumerateCompiledFunctions(heap, NULL, NULL);
sgjesse@chromium.org720dc0b2010-05-10 09:25:39 +00001714 ScopedVector< Handle<SharedFunctionInfo> > sfis(compiled_funcs_count);
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001715 ScopedVector< Handle<Code> > code_objects(compiled_funcs_count);
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001716 EnumerateCompiledFunctions(heap, sfis.start(), code_objects.start());
kasperl@chromium.org71affb52009-05-26 05:44:31 +00001717
1718 // During iteration, there can be heap allocation due to
1719 // GetScriptLineNumber call.
1720 for (int i = 0; i < compiled_funcs_count; ++i) {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001721 if (*code_objects[i] == Isolate::Current()->builtins()->builtin(
fschneider@chromium.org7979bbb2011-03-28 10:47:03 +00001722 Builtins::kLazyCompile))
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001723 continue;
lrn@chromium.org34e60782011-09-15 07:25:40 +00001724 LogExistingFunction(sfis[i], code_objects[i]);
kasperl@chromium.org71affb52009-05-26 05:44:31 +00001725 }
kasperl@chromium.org71affb52009-05-26 05:44:31 +00001726}
1727
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +00001728
1729void Logger::LogAccessorCallbacks() {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001730 Heap* heap = isolate_->heap();
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001731 heap->CollectAllGarbage(Heap::kMakeHeapIterableMask,
rossberg@chromium.org994edf62012-02-06 10:12:55 +00001732 "Logger::LogAccessorCallbacks");
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001733 HeapIterator iterator(heap);
erik.corry@gmail.comc3b670f2011-10-05 21:44:48 +00001734 AssertNoAllocation no_alloc;
sgjesse@chromium.orgb302e562010-02-03 11:26:59 +00001735 for (HeapObject* obj = iterator.next(); obj != NULL; obj = iterator.next()) {
hpayer@chromium.org7c3372b2013-02-13 17:26:04 +00001736 if (!obj->IsExecutableAccessorInfo()) continue;
1737 ExecutableAccessorInfo* ai = ExecutableAccessorInfo::cast(obj);
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +00001738 if (!ai->name()->IsString()) continue;
1739 String* name = String::cast(ai->name());
1740 Address getter_entry = v8::ToCData<Address>(ai->getter());
1741 if (getter_entry != 0) {
erik.corry@gmail.comc3b670f2011-10-05 21:44:48 +00001742 PROFILE(ISOLATE, GetterCallbackEvent(name, getter_entry));
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +00001743 }
1744 Address setter_entry = v8::ToCData<Address>(ai->setter());
1745 if (setter_entry != 0) {
erik.corry@gmail.comc3b670f2011-10-05 21:44:48 +00001746 PROFILE(ISOLATE, SetterCallbackEvent(name, setter_entry));
sgjesse@chromium.orgac6aa172009-12-04 12:29:05 +00001747 }
1748 }
1749}
1750
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001751
erik.corry@gmail.comf2038fb2012-01-16 11:42:08 +00001752bool Logger::SetUp() {
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001753 // Tests and EnsureInitialize() can call this twice in a row. It's harmless.
1754 if (is_initialized_) return true;
1755 is_initialized_ = true;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001756
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001757 // --ll-prof implies --log-code and --log-snapshot-positions.
1758 if (FLAG_ll_prof) {
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001759 FLAG_log_snapshot_positions = true;
1760 }
1761
kasperl@chromium.org71affb52009-05-26 05:44:31 +00001762 // --prof_lazy controls --log-code, implies --noprof_auto.
1763 if (FLAG_prof_lazy) {
1764 FLAG_log_code = false;
1765 FLAG_prof_auto = false;
1766 }
1767
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001768 // TODO(isolates): this assert introduces cyclic dependency (logger
1769 // -> thread local top -> heap -> logger).
1770 // ASSERT(VMState::is_outermost_external());
ager@chromium.org3e875802009-06-29 08:26:34 +00001771
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001772 log_->Initialize();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001773
whesse@chromium.org4a5224e2010-10-20 12:37:07 +00001774 if (FLAG_ll_prof) LogCodeInfo();
1775
fschneider@chromium.org7979bbb2011-03-28 10:47:03 +00001776 Isolate* isolate = Isolate::Current();
svenpanne@chromium.org6d786c92011-06-15 10:58:27 +00001777 ticker_ = new Ticker(isolate, kSamplingIntervalMs);
1778
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001779 bool start_logging = FLAG_log || FLAG_log_runtime || FLAG_log_api
1780 || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect
ulan@chromium.org8e8d8822012-11-23 14:36:46 +00001781 || FLAG_log_regexp || FLAG_log_state_changes || FLAG_ll_prof
mstarzinger@chromium.org32280cf2012-12-06 17:32:37 +00001782 || FLAG_log_internal_timer_events;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001783
ager@chromium.orgce5e87b2010-03-10 10:24:18 +00001784 if (start_logging) {
1785 logging_nesting_ = 1;
1786 }
ager@chromium.org3e875802009-06-29 08:26:34 +00001787
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001788 if (FLAG_prof) {
fschneider@chromium.org7979bbb2011-03-28 10:47:03 +00001789 profiler_ = new Profiler(isolate);
ager@chromium.org3e875802009-06-29 08:26:34 +00001790 if (!FLAG_prof_auto) {
iposva@chromium.org245aa852009-02-10 00:49:54 +00001791 profiler_->pause();
ager@chromium.org3e875802009-06-29 08:26:34 +00001792 } else {
ager@chromium.orgce5e87b2010-03-10 10:24:18 +00001793 logging_nesting_ = 1;
ager@chromium.org3e875802009-06-29 08:26:34 +00001794 }
ager@chromium.org3811b432009-10-28 14:53:37 +00001795 if (!FLAG_prof_lazy) {
1796 profiler_->Engage();
1797 }
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001798 }
1799
mstarzinger@chromium.org32280cf2012-12-06 17:32:37 +00001800 if (FLAG_log_internal_timer_events || FLAG_prof) epoch_ = OS::Ticks();
ulan@chromium.org8e8d8822012-11-23 14:36:46 +00001801
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001802 return true;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001803}
1804
1805
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001806void Logger::SetCodeEventHandler(uint32_t options,
1807 JitCodeEventHandler event_handler) {
1808 code_event_handler_ = event_handler;
1809
1810 if (code_event_handler_ != NULL && (options & kJitCodeEventEnumExisting)) {
yangguo@chromium.orgc03a1922013-02-19 13:55:47 +00001811 HandleScope scope(Isolate::Current());
yangguo@chromium.org355cfd12012-08-29 15:32:24 +00001812 LogCodeObjects();
1813 LogCompiledFunctions();
1814 }
1815}
1816
1817
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001818Sampler* Logger::sampler() {
1819 return ticker_;
1820}
1821
1822
kasperl@chromium.orga5551262010-12-07 12:49:48 +00001823void Logger::EnsureTickerStarted() {
1824 ASSERT(ticker_ != NULL);
1825 if (!ticker_->IsActive()) ticker_->Start();
1826}
1827
1828
1829void Logger::EnsureTickerStopped() {
1830 if (ticker_ != NULL && ticker_->IsActive()) ticker_->Stop();
1831}
1832
1833
whesse@chromium.org030d38e2011-07-13 13:23:34 +00001834FILE* Logger::TearDown() {
1835 if (!is_initialized_) return NULL;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001836 is_initialized_ = false;
sgjesse@chromium.org755c5b12009-05-29 11:04:38 +00001837
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001838 // Stop the profiler before closing the file.
1839 if (profiler_ != NULL) {
1840 profiler_->Disengage();
1841 delete profiler_;
1842 profiler_ = NULL;
1843 }
1844
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001845 delete ticker_;
kasperl@chromium.org71affb52009-05-26 05:44:31 +00001846 ticker_ = NULL;
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001847
whesse@chromium.org030d38e2011-07-13 13:23:34 +00001848 return log_->Close();
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001849}
1850
1851
jkummerow@chromium.org1456e702012-03-30 08:38:13 +00001852// Protects the state below.
fschneider@chromium.org7d10be52012-04-10 12:30:14 +00001853static Mutex* active_samplers_mutex = NULL;
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001854
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001855List<Sampler*>* SamplerRegistry::active_samplers_ = NULL;
1856
1857
fschneider@chromium.org7d10be52012-04-10 12:30:14 +00001858void SamplerRegistry::SetUp() {
1859 if (!active_samplers_mutex) {
1860 active_samplers_mutex = OS::CreateMutex();
1861 }
1862}
1863
1864
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001865bool SamplerRegistry::IterateActiveSamplers(VisitSampler func, void* param) {
fschneider@chromium.org7d10be52012-04-10 12:30:14 +00001866 ScopedLock lock(active_samplers_mutex);
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001867 for (int i = 0;
1868 ActiveSamplersExist() && i < active_samplers_->length();
1869 ++i) {
1870 func(active_samplers_->at(i), param);
1871 }
1872 return ActiveSamplersExist();
1873}
1874
1875
1876static void ComputeCpuProfiling(Sampler* sampler, void* flag_ptr) {
1877 bool* flag = reinterpret_cast<bool*>(flag_ptr);
1878 *flag |= sampler->IsProfiling();
1879}
1880
1881
1882SamplerRegistry::State SamplerRegistry::GetState() {
1883 bool flag = false;
1884 if (!IterateActiveSamplers(&ComputeCpuProfiling, &flag)) {
1885 return HAS_NO_SAMPLERS;
1886 }
1887 return flag ? HAS_CPU_PROFILING_SAMPLERS : HAS_SAMPLERS;
1888}
1889
1890
1891void SamplerRegistry::AddActiveSampler(Sampler* sampler) {
1892 ASSERT(sampler->IsActive());
fschneider@chromium.org7d10be52012-04-10 12:30:14 +00001893 ScopedLock lock(active_samplers_mutex);
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001894 if (active_samplers_ == NULL) {
1895 active_samplers_ = new List<Sampler*>;
1896 } else {
1897 ASSERT(!active_samplers_->Contains(sampler));
1898 }
1899 active_samplers_->Add(sampler);
1900}
1901
1902
1903void SamplerRegistry::RemoveActiveSampler(Sampler* sampler) {
1904 ASSERT(sampler->IsActive());
fschneider@chromium.org7d10be52012-04-10 12:30:14 +00001905 ScopedLock lock(active_samplers_mutex);
sgjesse@chromium.orgea88ce92011-03-23 11:19:56 +00001906 ASSERT(active_samplers_ != NULL);
1907 bool removed = active_samplers_->RemoveElement(sampler);
1908 ASSERT(removed);
1909 USE(removed);
1910}
1911
christian.plesner.hansen43d26ec2008-07-03 15:10:15 +00001912} } // namespace v8::internal