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

30
#ifdef __linux__
31
#include <pthread.h>
32 33
#include <signal.h>
#include <unistd.h>
34
#include <cmath>
35
#endif  // __linux__
36

37
#include <unordered_set>
38
#include <vector>
39 40 41
// The C++ style guide recommends using <re2> instead of <regex>. However, the
// former isn't available in V8.
#include <regex>  // NOLINT(build/c++11)
42
#include "src/api.h"
43
#include "src/log-utils.h"
44
#include "src/log.h"
45
#include "src/objects-inl.h"
46
#include "src/profiler/cpu-profiler.h"
47
#include "src/snapshot/natives.h"
48
#include "src/utils.h"
49
#include "src/v8.h"
50
#include "src/v8threads.h"
51
#include "src/version.h"
52 53
#include "src/vm-state-inl.h"
#include "test/cctest/cctest.h"
54

55
using v8::internal::Address;
56
using v8::internal::EmbeddedVector;
57
using v8::internal::Logger;
58
using v8::internal::StrLength;
59

60 61
namespace {

62

63 64 65 66 67 68 69 70
#define SETUP_FLAGS()                            \
  bool saved_log = i::FLAG_log;                  \
  bool saved_prof = i::FLAG_prof;                \
  i::FLAG_log = true;                            \
  i::FLAG_prof = true;                           \
  i::FLAG_logfile = i::Log::kLogToTemporaryFile; \
  i::FLAG_logfile_per_isolate = false

71 72 73 74 75
static const char* StrNStr(const char* s1, const char* s2, size_t n) {
  CHECK_EQ(s1[n], '\0');
  return strstr(s1, s2);
}

76
// Look for a log line which starts with {prefix} and ends with {suffix}.
77 78
static const char* FindLogLine(const char* start, const char* end,
                               const char* prefix,
79
                               const char* suffix = nullptr) {
80
  CHECK_LT(start, end);
81 82 83 84
  CHECK_EQ(end[0], '\0');
  size_t prefixLength = strlen(prefix);
  // Loop through the input until we find /{prefix}[^\n]+{suffix}/.
  while (start < end) {
85
    const char* prefixResult = strstr(start, prefix);
86
    if (!prefixResult) return NULL;
87
    if (suffix == nullptr) return prefixResult;
88 89 90 91 92 93 94 95 96 97 98 99 100
    const char* suffixResult =
        StrNStr(prefixResult, suffix, (end - prefixResult));
    if (!suffixResult) return NULL;
    // Check that there are no newlines in between the {prefix} and the {suffix}
    // results.
    const char* newlineResult =
        StrNStr(prefixResult, "\n", (end - prefixResult));
    if (!newlineResult) return prefixResult;
    if (newlineResult > suffixResult) return prefixResult;
    start = prefixResult + prefixLength;
  }
  return NULL;
}
101

102 103
class ScopedLoggerInitializer {
 public:
104 105 106
  ScopedLoggerInitializer(bool saved_log, bool saved_prof, v8::Isolate* isolate)
      : saved_log_(saved_log),
        saved_prof_(saved_prof),
107
        temp_file_(nullptr),
108 109 110 111 112
        isolate_(isolate),
        isolate_scope_(isolate),
        scope_(isolate),
        env_(v8::Context::New(isolate)),
        logger_(reinterpret_cast<i::Isolate*>(isolate)->logger()) {
113 114 115 116 117
    env_->Enter();
  }

  ~ScopedLoggerInitializer() {
    env_->Exit();
yurys@chromium.org's avatar
yurys@chromium.org committed
118
    logger_->TearDown();
119
    if (temp_file_ != nullptr) fclose(temp_file_);
120
    i::FLAG_prof = saved_prof_;
121
    i::FLAG_log = saved_log_;
122
    log_.Dispose();
123 124
  }

125
  v8::Local<v8::Context>& env() { return env_; }
126

127 128
  v8::Isolate* isolate() { return isolate_; }

129 130
  i::Isolate* i_isolate() { return reinterpret_cast<i::Isolate*>(isolate()); }

yurys@chromium.org's avatar
yurys@chromium.org committed
131 132
  Logger* logger() { return logger_; }

133 134
  void PrintLog(int requested_nof_lines = 0, const char* start = nullptr) {
    if (requested_nof_lines <= 0) {
135 136 137
      printf("%s", log_.start());
      return;
    }
138 139
    // Try to print the last {requested_nof_lines} of the log.
    if (start == nullptr) start = log_.start();
140
    const char* current = log_.end();
141 142
    int nof_lines = requested_nof_lines;
    while (current > start && nof_lines > 0) {
143
      current--;
144
      if (*current == '\n') nof_lines--;
145 146 147
    }
    printf(
        "======================================================\n"
148 149 150
        "Last %i log lines:\n"
        "======================================================\n"
        "...\n%s\n"
151
        "======================================================\n",
152
        requested_nof_lines, current);
153
  }
154

155 156 157 158 159 160 161 162 163 164 165 166
  v8::Local<v8::String> GetLogString() {
    return v8::String::NewFromUtf8(isolate_, log_.start(),
                                   v8::NewStringType::kNormal, log_.length())
        .ToLocalChecked();
  }

  void StopLogging() {
    bool exists = false;
    log_ = i::ReadFile(StopLoggingGetTempFile(), &exists, true);
    CHECK(exists);
  }

167 168
  const char* GetEndPosition() { return log_.start() + log_.length(); }

169 170
  const char* FindLine(const char* prefix, const char* suffix = nullptr,
                       const char* start = nullptr) {
171 172
    // Make sure that StopLogging() has been called before.
    CHECK(log_.size());
173
    if (start == nullptr) start = log_.start();
174
    const char* end = GetEndPosition();
175
    return FindLogLine(start, end, prefix, suffix);
176 177
  }

178 179
  // Find all log lines specified by the {prefix, suffix} pairs and ensure they
  // occurr in the specified order.
180 181 182 183 184 185
  void FindLogLines(const char* pairs[][2], size_t limit,
                    const char* start = nullptr) {
    const char* prefix = pairs[0][0];
    const char* suffix = pairs[0][1];
    const char* last_position = FindLine(prefix, suffix, start);
    if (last_position == nullptr) {
186
      PrintLog(100, start);
187 188 189
      V8_Fatal(__FILE__, __LINE__, "Could not find log line: %s ... %s", prefix,
               suffix);
    }
190 191
    CHECK(last_position);
    for (size_t i = 1; i < limit; i++) {
192 193 194 195
      prefix = pairs[i][0];
      suffix = pairs[i][1];
      const char* position = FindLine(prefix, suffix, start);
      if (position == nullptr) {
196
        PrintLog(100, start);
197 198 199
        V8_Fatal(__FILE__, __LINE__, "Could not find log line: %s ... %s",
                 prefix, suffix);
      }
200
      // Check that all string positions are in order.
201
      if (position <= last_position) {
202
        PrintLog(100, start);
203 204 205 206 207 208
        V8_Fatal(__FILE__, __LINE__,
                 "Log statements not in expected order (prev=%p, current=%p): "
                 "%s ... %s",
                 reinterpret_cast<const void*>(last_position),
                 reinterpret_cast<const void*>(position), prefix, suffix);
      }
209 210 211 212
      last_position = position;
    }
  }

213 214 215 216 217 218
  void LogCompiledFunctions() { logger_->LogCompiledFunctions(); }

  void StringEvent(const char* name, const char* value) {
    logger_->StringEvent(name, value);
  }

219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242
  void ExtractAllAddresses(std::unordered_set<uintptr_t>* map,
                           const char* prefix, int field_index) {
    // Make sure that StopLogging() has been called before.
    CHECK(log_.size());
    const char* current = log_.start();
    while (current != nullptr) {
      current = FindLine(prefix, nullptr, current);
      if (current == nullptr) return;
      // Find token number {index}.
      const char* previous;
      for (int i = 0; i <= field_index; i++) {
        previous = current;
        current = strchr(current + 1, ',');
        if (current == nullptr) break;
        // Skip the comma.
        current++;
      }
      if (current == nullptr) break;
      uintptr_t address = strtoll(previous, nullptr, 16);
      CHECK_LT(0, address);
      map->insert(address);
    }
  }

243
 private:
244
  FILE* StopLoggingGetTempFile() {
yurys@chromium.org's avatar
yurys@chromium.org committed
245
    temp_file_ = logger_->TearDown();
246
    CHECK(temp_file_);
247 248 249 250 251 252
    fflush(temp_file_);
    rewind(temp_file_);
    return temp_file_;
  }

  const bool saved_log_;
253
  const bool saved_prof_;
254
  FILE* temp_file_;
255 256
  v8::Isolate* isolate_;
  v8::Isolate::Scope isolate_scope_;
257
  v8::HandleScope scope_;
258
  v8::Local<v8::Context> env_;
yurys@chromium.org's avatar
yurys@chromium.org committed
259
  Logger* logger_;
260
  i::Vector<const char> log_;
261 262 263 264

  DISALLOW_COPY_AND_ASSIGN(ScopedLoggerInitializer);
};

265 266 267 268 269
class TestCodeEventHandler : public v8::CodeEventHandler {
 public:
  explicit TestCodeEventHandler(v8::Isolate* isolate)
      : v8::CodeEventHandler(isolate) {}

270 271 272 273 274 275 276 277 278 279
  size_t CountLines(std::string prefix, std::string suffix = std::string()) {
    if (!log_.length()) return 0;

    std::regex expression("(^|\\n)" + prefix + ".*" + suffix + "(?=\\n|$)");

    size_t match_count(std::distance(
        std::sregex_iterator(log_.begin(), log_.end(), expression),
        std::sregex_iterator()));

    return match_count;
280 281 282
  }

  void Handle(v8::CodeEvent* code_event) override {
283 284 285 286 287 288
    std::string log_line = "";
    log_line += v8::CodeEvent::GetCodeEventTypeName(code_event->GetCodeType());
    log_line += " ";
    log_line += FormatName(code_event);
    log_line += "\n";
    log_ += log_line;
289 290 291
  }

 private:
292 293 294 295 296 297 298 299 300 301 302 303 304
  std::string FormatName(v8::CodeEvent* code_event) {
    std::string name = std::string(code_event->GetComment());
    if (name.empty()) {
      v8::Local<v8::String> functionName = code_event->GetFunctionName();
      std::string buffer(functionName->Utf8Length() + 1, 0);
      functionName->WriteUtf8(&buffer[0], functionName->Utf8Length() + 1);
      // Sanitize name, removing unwanted \0 resulted from WriteUtf8
      name = std::string(buffer.c_str());
    }

    return name;
  }

305 306 307
  std::string log_;
};

308 309
}  // namespace

310 311 312 313 314 315
TEST(FindLogLine) {
  const char* string =
      "prefix1, stuff,   suffix1\n"
      "prefix2, stuff\n, suffix2\n"
      "prefix3suffix3\n"
      "prefix4 suffix4";
316
  const char* end = string + strlen(string);
317
  // Make sure the vector contains the terminating \0 character.
318 319 320 321 322 323 324 325 326 327 328 329 330 331
  CHECK(FindLogLine(string, end, "prefix1, stuff,   suffix1"));
  CHECK(FindLogLine(string, end, "prefix1, stuff"));
  CHECK(FindLogLine(string, end, "prefix1"));
  CHECK(FindLogLine(string, end, "prefix1", "suffix1"));
  CHECK(FindLogLine(string, end, "prefix1", "suffix1"));
  CHECK(!FindLogLine(string, end, "prefix2", "suffix2"));
  CHECK(!FindLogLine(string, end, "prefix1", "suffix2"));
  CHECK(!FindLogLine(string, end, "prefix1", "suffix3"));
  CHECK(FindLogLine(string, end, "prefix3", "suffix3"));
  CHECK(FindLogLine(string, end, "prefix4", "suffix4"));
  CHECK(!FindLogLine(string, end, "prefix4", "suffix4XXXXXXXXXXXX"));
  CHECK(
      !FindLogLine(string, end, "prefix4XXXXXXXXXXXXXXXXXXXXXXxxx", "suffix4"));
  CHECK(!FindLogLine(string, end, "suffix", "suffix5XXXXXXXXXXXXXXXXXXXX"));
332 333
}

334 335
// BUG(913). Need to implement support for profiling multiple VM threads.
#if 0
336 337 338 339 340

namespace {

class LoopingThread : public v8::internal::Thread {
 public:
341 342
  explicit LoopingThread(v8::internal::Isolate* isolate)
      : v8::internal::Thread(isolate),
343
        semaphore_(new v8::internal::Semaphore(0)),
344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368 369 370 371 372 373 374 375 376 377 378 379 380
        run_(true) {
  }

  virtual ~LoopingThread() { delete semaphore_; }

  void Run() {
    self_ = pthread_self();
    RunLoop();
  }

  void SendSigProf() { pthread_kill(self_, SIGPROF); }

  void Stop() { run_ = false; }

  bool WaitForRunning() { return semaphore_->Wait(1000000); }

 protected:
  bool IsRunning() { return run_; }

  virtual void RunLoop() = 0;

  void SetV8ThreadId() {
    v8_thread_id_ = v8::V8::GetCurrentThreadId();
  }

  void SignalRunning() { semaphore_->Signal(); }

 private:
  v8::internal::Semaphore* semaphore_;
  bool run_;
  pthread_t self_;
  int v8_thread_id_;
};


class LoopingJsThread : public LoopingThread {
 public:
381 382
  explicit LoopingJsThread(v8::internal::Isolate* isolate)
      : LoopingThread(isolate) { }
383
  void RunLoop() {
384
    v8::Locker locker;
385
    CHECK_NOT_NULL(CcTest::i_isolate());
386
    CHECK_GT(CcTest::i_isolate()->thread_manager()->CurrentId(), 0);
387
    SetV8ThreadId();
388 389 390
    while (IsRunning()) {
      v8::HandleScope scope;
      v8::Persistent<v8::Context> context = v8::Context::New();
391 392 393 394
      CHECK(!context.IsEmpty());
      {
        v8::Context::Scope context_scope(context);
        SignalRunning();
395
        CompileRun(
396 397
            "var j; for (var i=0; i<10000; ++i) { j = Math.sin(i); }");
      }
398
      context.Dispose();
399
      i::OS::Sleep(v8::base::TimeDelta::FromMilliseconds(1));
400 401 402 403 404 405 406
    }
  }
};


class LoopingNonJsThread : public LoopingThread {
 public:
407 408
  explicit LoopingNonJsThread(v8::internal::Isolate* isolate)
      : LoopingThread(isolate) { }
409 410 411 412
  void RunLoop() {
    v8::Locker locker;
    v8::Unlocker unlocker;
    // Now thread has V8's id, but will not run VM code.
413
    CHECK_NOT_NULL(CcTest::i_isolate());
414
    CHECK_GT(CcTest::i_isolate()->thread_manager()->CurrentId(), 0);
415 416 417
    double i = 10;
    SignalRunning();
    while (IsRunning()) {
418
      i = std::sin(i);
419
      i::OS::Sleep(v8::base::TimeDelta::FromMilliseconds(1));
420 421 422 423 424 425 426
    }
  }
};


class TestSampler : public v8::internal::Sampler {
 public:
427 428
  explicit TestSampler(v8::internal::Isolate* isolate)
      : Sampler(isolate, 0, true, true),
429
        semaphore_(new v8::internal::Semaphore(0)),
430 431 432 433 434 435 436 437 438 439 440 441 442 443 444 445 446 447 448 449 450 451 452 453 454 455
        was_sample_stack_called_(false) {
  }

  ~TestSampler() { delete semaphore_; }

  void SampleStack(v8::internal::TickSample*) {
    was_sample_stack_called_ = true;
  }

  void Tick(v8::internal::TickSample*) { semaphore_->Signal(); }

  bool WaitForTick() { return semaphore_->Wait(1000000); }

  void Reset() { was_sample_stack_called_ = false; }

  bool WasSampleStackCalled() { return was_sample_stack_called_; }

 private:
  v8::internal::Semaphore* semaphore_;
  bool was_sample_stack_called_;
};


}  // namespace

TEST(ProfMultipleThreads) {
456
  TestSampler* sampler = nullptr;
457 458
  {
    v8::Locker locker;
459
    sampler = new TestSampler(CcTest::i_isolate());
460 461 462 463
    sampler->Start();
    CHECK(sampler->IsActive());
  }

464
  LoopingJsThread jsThread(CcTest::i_isolate());
465
  jsThread.Start();
466
  LoopingNonJsThread nonJsThread(CcTest::i_isolate());
467 468
  nonJsThread.Start();

469
  CHECK(!sampler->WasSampleStackCalled());
470 471
  jsThread.WaitForRunning();
  jsThread.SendSigProf();
472 473 474 475
  CHECK(sampler->WaitForTick());
  CHECK(sampler->WasSampleStackCalled());
  sampler->Reset();
  CHECK(!sampler->WasSampleStackCalled());
476 477
  nonJsThread.WaitForRunning();
  nonJsThread.SendSigProf();
478 479 480
  CHECK(!sampler->WaitForTick());
  CHECK(!sampler->WasSampleStackCalled());
  sampler->Stop();
481 482 483 484 485

  jsThread.Stop();
  nonJsThread.Stop();
  jsThread.Join();
  nonJsThread.Join();
486 487

  delete sampler;
488 489 490 491 492
}

#endif  // __linux__


493 494 495 496 497 498 499 500
// Test for issue http://crbug.com/23768 in Chromium.
// Heap can contain scripts with already disposed external sources.
// We need to verify that LogCompiledFunctions doesn't crash on them.
namespace {

class SimpleExternalString : public v8::String::ExternalStringResource {
 public:
  explicit SimpleExternalString(const char* source)
501
      : utf_source_(StrLength(source)) {
502 503 504 505 506 507 508 509 510 511 512 513 514
    for (int i = 0; i < utf_source_.length(); ++i)
      utf_source_[i] = source[i];
  }
  virtual ~SimpleExternalString() {}
  virtual size_t length() const { return utf_source_.length(); }
  virtual const uint16_t* data() const { return utf_source_.start(); }
 private:
  i::ScopedVector<uint16_t> utf_source_;
};

}  // namespace

TEST(Issue23768) {
515
  v8::HandleScope scope(CcTest::isolate());
516
  v8::Local<v8::Context> env = v8::Context::New(CcTest::isolate());
517 518 519
  env->Enter();

  SimpleExternalString source_ext_str("(function ext() {})();");
520
  v8::Local<v8::String> source =
521 522
      v8::String::NewExternalTwoByte(CcTest::isolate(), &source_ext_str)
          .ToLocalChecked();
523
  // Script needs to have a name in order to trigger InitLineEnds execution.
524 525 526 527 528
  v8::Local<v8::String> origin =
      v8::String::NewFromUtf8(CcTest::isolate(), "issue-23768-test",
                              v8::NewStringType::kNormal)
          .ToLocalChecked();
  v8::Local<v8::Script> evil_script = CompileWithOrigin(source, origin);
529
  CHECK(!evil_script.IsEmpty());
530
  CHECK(!evil_script->Run(env).IsEmpty());
531
  i::Handle<i::ExternalTwoByteString> i_source(
532 533
      i::ExternalTwoByteString::cast(*v8::Utils::OpenHandle(*source)),
      CcTest::i_isolate());
534 535
  // This situation can happen if source was an external string disposed
  // by its owner.
536
  i_source->set_resource(nullptr);
537 538

  // Must not crash.
539
  CcTest::i_isolate()->logger()->LogCompiledFunctions();
540 541 542
}


543
static void ObjMethod1(const v8::FunctionCallbackInfo<v8::Value>& args) {
544 545
}

546

547
TEST(LogCallbacks) {
548 549 550 551
  SETUP_FLAGS();
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);
552
  {
553
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
554 555 556 557

    v8::Local<v8::FunctionTemplate> obj = v8::Local<v8::FunctionTemplate>::New(
        isolate, v8::FunctionTemplate::New(isolate));
    obj->SetClassName(v8_str("Obj"));
558
    v8::Local<v8::ObjectTemplate> proto = obj->PrototypeTemplate();
559 560 561
    v8::Local<v8::Signature> signature = v8::Signature::New(isolate, obj);
    proto->Set(v8_str("method1"),
               v8::FunctionTemplate::New(isolate, ObjMethod1,
562
                                         v8::Local<v8::Value>(), signature),
563 564
               static_cast<v8::PropertyAttribute>(v8::DontDelete));

565
    logger.env()
566
        ->Global()
567 568
        ->Set(logger.env(), v8_str("Obj"),
              obj->GetFunction(logger.env()).ToLocalChecked())
569
        .FromJust();
570 571
    CompileRun("Obj.prototype.method1.toString();");

572
    logger.LogCompiledFunctions();
573

574
    logger.StopLogging();
575

576 577 578 579
    Address ObjMethod1_entry = reinterpret_cast<Address>(ObjMethod1);
#if USES_FUNCTION_DESCRIPTORS
    ObjMethod1_entry = *FUNCTION_ENTRYPOINT_ADDRESS(ObjMethod1_entry);
#endif
580
    i::EmbeddedVector<char, 100> ref_data;
581
    i::SNPrintF(ref_data, ",0x%" V8PRIxPTR ",1,method1", ObjMethod1_entry);
582
    CHECK(logger.FindLine("code-creation,Callback,-2,", ref_data.start()));
583 584
  }
  isolate->Dispose();
585 586 587
}


588 589
static void Prop1Getter(v8::Local<v8::String> property,
                        const v8::PropertyCallbackInfo<v8::Value>& info) {
590 591 592
}

static void Prop1Setter(v8::Local<v8::String> property,
593 594
                        v8::Local<v8::Value> value,
                        const v8::PropertyCallbackInfo<void>& info) {
595 596
}

597 598
static void Prop2Getter(v8::Local<v8::String> property,
                        const v8::PropertyCallbackInfo<v8::Value>& info) {
599 600
}

601

602
TEST(LogAccessorCallbacks) {
603 604 605 606
  SETUP_FLAGS();
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);
607
  {
608
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
609 610 611 612

    v8::Local<v8::FunctionTemplate> obj = v8::Local<v8::FunctionTemplate>::New(
        isolate, v8::FunctionTemplate::New(isolate));
    obj->SetClassName(v8_str("Obj"));
613
    v8::Local<v8::ObjectTemplate> inst = obj->InstanceTemplate();
614 615 616
    inst->SetAccessor(v8_str("prop1"), Prop1Getter, Prop1Setter);
    inst->SetAccessor(v8_str("prop2"), Prop2Getter);

617
    logger.logger()->LogAccessorCallbacks();
618

619
    logger.StopLogging();
620

621 622 623 624
    Address Prop1Getter_entry = reinterpret_cast<Address>(Prop1Getter);
#if USES_FUNCTION_DESCRIPTORS
    Prop1Getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(Prop1Getter_entry);
#endif
625
    EmbeddedVector<char, 100> prop1_getter_record;
626
    i::SNPrintF(prop1_getter_record, ",0x%" V8PRIxPTR ",1,get prop1",
627
                Prop1Getter_entry);
628 629
    CHECK(logger.FindLine("code-creation,Callback,-2,",
                          prop1_getter_record.start()));
630

631 632 633 634
    Address Prop1Setter_entry = reinterpret_cast<Address>(Prop1Setter);
#if USES_FUNCTION_DESCRIPTORS
    Prop1Setter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(Prop1Setter_entry);
#endif
635
    EmbeddedVector<char, 100> prop1_setter_record;
636
    i::SNPrintF(prop1_setter_record, ",0x%" V8PRIxPTR ",1,set prop1",
637
                Prop1Setter_entry);
638 639
    CHECK(logger.FindLine("code-creation,Callback,-2,",
                          prop1_setter_record.start()));
640

641 642 643 644
    Address Prop2Getter_entry = reinterpret_cast<Address>(Prop2Getter);
#if USES_FUNCTION_DESCRIPTORS
    Prop2Getter_entry = *FUNCTION_ENTRYPOINT_ADDRESS(Prop2Getter_entry);
#endif
645
    EmbeddedVector<char, 100> prop2_getter_record;
646
    i::SNPrintF(prop2_getter_record, ",0x%" V8PRIxPTR ",1,get prop2",
647
                Prop2Getter_entry);
648 649
    CHECK(logger.FindLine("code-creation,Callback,-2,",
                          prop2_getter_record.start()));
650 651
  }
  isolate->Dispose();
652
}
653

654 655
// Test that logging of code create / move events is equivalent to traversal of
// a resulting heap.
656
TEST(EquivalenceOfLoggingAndTraversal) {
657 658 659 660 661 662
  // This test needs to be run on a "clean" V8 to ensure that snapshot log
  // is loaded. This is always true when running using tools/test.py because
  // it launches a new cctest instance for every test. To be sure that launching
  // cctest manually also works, please be sure that no tests below
  // are using V8.

663
  // Start with profiling to capture all code events from the beginning.
664 665 666 667
  SETUP_FLAGS();
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);
668
  {
669
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
670 671 672 673 674 675 676

    // Compile and run a function that creates other functions.
    CompileRun(
        "(function f(obj) {\n"
        "  obj.test =\n"
        "    (function a(j) { return function b() { return j; } })(100);\n"
        "})(this);");
677
    logger.logger()->StopProfiler();
678
    reinterpret_cast<i::Isolate*>(isolate)->heap()->CollectAllGarbage(
679
        i::Heap::kMakeHeapIterableMask, i::GarbageCollectionReason::kTesting);
680
    logger.StringEvent("test-logging-done", "");
681 682

    // Iterate heap to find compiled functions, will write to log.
683 684
    logger.LogCompiledFunctions();
    logger.StringEvent("test-traversal-done", "");
685

686 687 688 689
    logger.StopLogging();

    v8::Local<v8::String> log_str = logger.GetLogString();
    logger.env()
690
        ->Global()
691
        ->Set(logger.env(), v8_str("_log"), log_str)
692
        .FromJust();
693

694 695 696
    // Load the Test snapshot's sources, see log-eq-of-logging-and-traversal.js
    i::Vector<const char> source =
        i::NativesCollection<i::TEST>::GetScriptsSource();
697 698 699 700
    v8::Local<v8::String> source_str =
        v8::String::NewFromUtf8(isolate, source.start(),
                                v8::NewStringType::kNormal, source.length())
            .ToLocalChecked();
701
    v8::TryCatch try_catch(isolate);
702
    v8::Local<v8::Script> script = CompileWithOrigin(source_str, "");
703
    if (script.IsEmpty()) {
704
      v8::String::Utf8Value exception(isolate, try_catch.Exception());
705
      FATAL("compile: %s\n", *exception);
706
    }
707
    v8::Local<v8::Value> result;
708
    if (!script->Run(logger.env()).ToLocal(&result)) {
709
      v8::String::Utf8Value exception(isolate, try_catch.Exception());
710
      FATAL("run: %s\n", *exception);
711
    }
712
    // The result either be the "true" literal or problem description.
713
    if (!result->IsTrue()) {
714
      v8::Local<v8::String> s = result->ToString(logger.env()).ToLocalChecked();
715
      i::ScopedVector<char> data(s->Utf8Length() + 1);
716
      CHECK(data.start());
717
      s->WriteUtf8(data.start());
718
      FATAL("%s\n", data.start());
719
    }
720
  }
721
  isolate->Dispose();
722
}
723 724 725


TEST(LogVersion) {
726 727 728 729
  SETUP_FLAGS();
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);
730
  {
731 732 733
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
    logger.StopLogging();

734
    i::EmbeddedVector<char, 100> ref_data;
735
    i::SNPrintF(ref_data, "%d,%d,%d,%d,%d", i::Version::GetMajor(),
736 737
                i::Version::GetMinor(), i::Version::GetBuild(),
                i::Version::GetPatch(), i::Version::IsCandidate());
738
    CHECK(logger.FindLine("v8-version,", ref_data.start()));
739 740 741
  }
  isolate->Dispose();
}
742 743 744 745 746 747 748


// https://crbug.com/539892
// CodeCreateEvents with really large names should not crash.
TEST(Issue539892) {
  class : public i::CodeEventLogger {
   public:
749 750 751
    void CodeMoveEvent(i::AbstractCode* from, Address to) override {}
    void CodeDisableOptEvent(i::AbstractCode* code,
                             i::SharedFunctionInfo* shared) override {}
752 753

   private:
754 755
    void LogRecordedBuffer(i::AbstractCode* code, i::SharedFunctionInfo* shared,
                           const char* name, int length) override {}
756
    void LogRecordedBuffer(const i::wasm::WasmCode* code, const char* name,
757
                           int length) override {}
758 759 760 761 762 763 764
  } code_event_logger;
  SETUP_FLAGS();
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);

  {
765
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
766
    logger.logger()->AddCodeEventListener(&code_event_logger);
767 768 769 770 771 772 773 774 775 776 777 778 779 780 781 782 783 784 785 786 787 788 789 790 791 792

    // Function with a really large name.
    const char* source_text =
        "(function "
        "baaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
        "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaac"
        "(){})();";

    CompileRun(source_text);

    // Must not crash.
793
    logger.LogCompiledFunctions();
794 795 796
  }
  isolate->Dispose();
}
797 798 799 800 801 802 803 804 805 806 807 808 809 810 811 812 813 814 815 816 817 818 819 820 821 822 823 824 825 826 827 828 829 830 831 832 833

TEST(LogAll) {
  SETUP_FLAGS();
  i::FLAG_log_all = true;
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);

  {
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);

    // Function that will
    const char* source_text =
        "function testAddFn(a,b) { return a + b };"
        "let result;"
        "for (let i = 0; i < 100000; i++) { result = testAddFn(i, i); };"
        "testAddFn('1', 1);"
        "for (let i = 0; i < 100000; i++) { result = testAddFn('1', i); }";
    CompileRun(source_text);

    logger.StopLogging();

    // We should find at least one code-creation even for testAddFn();
    CHECK(logger.FindLine("api,v8::Context::New"));
    CHECK(logger.FindLine("timer-event-start", "V8.CompileCode"));
    CHECK(logger.FindLine("timer-event-end", "V8.CompileCode"));
    CHECK(logger.FindLine("code-creation,Script", ":1:1"));
    CHECK(logger.FindLine("api,v8::Script::Run"));
    CHECK(logger.FindLine("code-creation,LazyCompile,", "testAddFn"));
    if (i::FLAG_opt && !i::FLAG_always_opt) {
      CHECK(logger.FindLine("code-deopt,", "soft"));
      CHECK(logger.FindLine("timer-event-start", "V8.DeoptimizeCode"));
      CHECK(logger.FindLine("timer-event-end", "V8.DeoptimizeCode"));
    }
  }
  isolate->Dispose();
}
834

835 836 837 838 839 840 841 842 843 844 845 846 847 848 849 850 851 852 853 854 855 856 857
TEST(LogInterpretedFramesNativeStack) {
  SETUP_FLAGS();
  i::FLAG_interpreted_frames_native_stack = true;
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);

  {
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);

    const char* source_text =
        "function testLogInterpretedFramesNativeStack(a,b) { return a + b };"
        "testLogInterpretedFramesNativeStack('1', 1);";
    CompileRun(source_text);

    logger.StopLogging();

    CHECK(logger.FindLine("InterpretedFunction",
                          "testLogInterpretedFramesNativeStack"));
  }
  isolate->Dispose();
}

858 859 860 861 862 863 864 865 866 867 868 869 870 871 872 873 874 875 876 877 878
TEST(ExternalCodeEventListener) {
  i::FLAG_log = false;
  i::FLAG_prof = false;

  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);

  {
    v8::HandleScope scope(isolate);
    v8::Isolate::Scope isolate_scope(isolate);
    v8::Local<v8::Context> context = v8::Context::New(isolate);
    context->Enter();

    TestCodeEventHandler code_event_handler(isolate);

    const char* source_text_before_start =
        "function testCodeEventListenerBeforeStart(a,b) { return a + b };"
        "testCodeEventListenerBeforeStart('1', 1);";
    CompileRun(source_text_before_start);

879 880 881
    CHECK_EQ(code_event_handler.CountLines("LazyCompile",
                                           "testCodeEventListenerBeforeStart"),
             0);
882 883 884

    code_event_handler.Enable();

885 886 887
    CHECK_GE(code_event_handler.CountLines("LazyCompile",
                                           "testCodeEventListenerBeforeStart"),
             1);
888 889 890 891 892 893

    const char* source_text_after_start =
        "function testCodeEventListenerAfterStart(a,b) { return a + b };"
        "testCodeEventListenerAfterStart('1', 1);";
    CompileRun(source_text_after_start);

894 895 896
    CHECK_GE(code_event_handler.CountLines("LazyCompile",
                                           "testCodeEventListenerAfterStart"),
             1);
897 898 899 900 901 902

    context->Exit();
  }
  isolate->Dispose();
}

903 904 905 906 907 908 909 910 911 912 913 914 915 916 917 918 919 920 921 922 923 924
TEST(ExternalCodeEventListenerWithInterpretedFramesNativeStack) {
  i::FLAG_log = false;
  i::FLAG_prof = false;
  i::FLAG_interpreted_frames_native_stack = true;

  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);

  {
    v8::HandleScope scope(isolate);
    v8::Isolate::Scope isolate_scope(isolate);
    v8::Local<v8::Context> context = v8::Context::New(isolate);
    context->Enter();

    TestCodeEventHandler code_event_handler(isolate);

    const char* source_text_before_start =
        "function testCodeEventListenerBeforeStart(a,b) { return a + b };"
        "testCodeEventListenerBeforeStart('1', 1);";
    CompileRun(source_text_before_start);

925 926 927
    CHECK_EQ(code_event_handler.CountLines("InterpretedFunction",
                                           "testCodeEventListenerBeforeStart"),
             0);
928 929 930

    code_event_handler.Enable();

931 932 933
    CHECK_GE(code_event_handler.CountLines("InterpretedFunction",
                                           "testCodeEventListenerBeforeStart"),
             1);
934 935 936 937 938 939

    const char* source_text_after_start =
        "function testCodeEventListenerAfterStart(a,b) { return a + b };"
        "testCodeEventListenerAfterStart('1', 1);";
    CompileRun(source_text_after_start);

940 941 942 943 944 945 946
    CHECK_GE(code_event_handler.CountLines("InterpretedFunction",
                                           "testCodeEventListenerAfterStart"),
             1);

    CHECK_EQ(
        code_event_handler.CountLines("Builtin", "InterpreterEntryTrampoline"),
        1);
947 948 949 950 951 952

    context->Exit();
  }
  isolate->Dispose();
}

953 954 955 956 957 958 959 960 961 962 963 964 965 966 967 968 969 970 971 972 973 974 975 976 977 978 979 980 981 982
TEST(TraceMaps) {
  SETUP_FLAGS();
  i::FLAG_trace_maps = true;
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);
  {
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
    // Try to create many different kind of maps to make sure the logging won't
    // crash. More detailed tests are implemented separately.
    const char* source_text =
        "let a = {};"
        "for (let i = 0; i < 500; i++) { a['p'+i] = i };"
        "class Test { constructor(i) { this.a = 1; this['p'+i] = 1; }};"
        "let t = new Test();"
        "t.b = 1; t.c = 1; t.d = 3;"
        "for (let i = 0; i < 100; i++) { t = new Test(i) };"
        "t.b = {};";
    CompileRun(source_text);

    logger.StopLogging();

    // Mostly superficial checks.
    CHECK(logger.FindLine("map,InitialMap", ",0x"));
    CHECK(logger.FindLine("map,Transition", ",0x"));
    CHECK(logger.FindLine("map-details", ",0x"));
  }
  i::FLAG_trace_maps = false;
  isolate->Dispose();
}
983

984 985 986 987 988 989 990 991 992 993 994 995 996 997 998 999 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009
TEST(LogMaps) {
  // Test that all Map details from Maps in the snapshot are logged properly.
  SETUP_FLAGS();
  i::FLAG_trace_maps = true;
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);
  {
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
    logger.StopLogging();
    // Extract all the map-detail entry addresses from the log.
    std::unordered_set<uintptr_t> map_addresses;
    logger.ExtractAllAddresses(&map_addresses, "map-details", 2);
    i::Heap* heap = reinterpret_cast<i::Isolate*>(isolate)->heap();
    i::HeapIterator iterator(heap);
    i::DisallowHeapAllocation no_gc;

    // Iterate over all maps on the heap.
    size_t i = 0;
    for (i::HeapObject* obj = iterator.next(); obj != nullptr;
         obj = iterator.next()) {
      i++;
      if (!obj->IsMap()) continue;
      uintptr_t address = reinterpret_cast<uintptr_t>(obj);
      if (map_addresses.find(address) != map_addresses.end()) continue;
      logger.PrintLog(200);
1010
      i::Map::cast(obj)->Print(heap->isolate());
1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022
      V8_Fatal(__FILE__, __LINE__,
               "Map (%p, #%zu) was not logged during startup with --trace-maps!"
               "\n# Expected Log Line: map_details, ... %p"
               "\n# Use logger::PrintLog() for more details.",
               reinterpret_cast<void*>(obj), i, reinterpret_cast<void*>(obj));
    }
    logger.PrintLog(200);
  }
  i::FLAG_log_function_events = false;
  isolate->Dispose();
}

1023 1024 1025 1026 1027 1028 1029 1030 1031 1032 1033 1034 1035 1036 1037 1038 1039 1040 1041 1042 1043 1044 1045 1046 1047 1048 1049 1050 1051 1052 1053 1054
TEST(ConsoleTimeEvents) {
  SETUP_FLAGS();
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);
  {
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
    // Test that console time events are properly logged
    const char* source_text =
        "console.time();"
        "console.timeEnd();"
        "console.timeStamp();"
        "console.time('timerEvent1');"
        "console.timeEnd('timerEvent1');"
        "console.timeStamp('timerEvent2');"
        "console.timeStamp('timerEvent3');";
    CompileRun(source_text);

    logger.StopLogging();

    const char* pairs[][2] = {{"timer-event-start,default,", nullptr},
                              {"timer-event-end,default,", nullptr},
                              {"timer-event,default,", nullptr},
                              {"timer-event-start,timerEvent1,", nullptr},
                              {"timer-event-end,timerEvent1,", nullptr},
                              {"timer-event,timerEvent2,", nullptr},
                              {"timer-event,timerEvent3,", nullptr}};
    logger.FindLogLines(pairs, arraysize(pairs));
  }

  isolate->Dispose();
}
1055 1056

TEST(LogFunctionEvents) {
1057 1058 1059
  // Always opt and stress opt will break the fine-grained log order.
  if (i::FLAG_always_opt) return;

1060 1061 1062 1063 1064
  SETUP_FLAGS();
  i::FLAG_log_function_events = true;
  v8::Isolate::CreateParams create_params;
  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
  v8::Isolate* isolate = v8::Isolate::New(create_params);
1065

1066 1067
  {
    ScopedLoggerInitializer logger(saved_log, saved_prof, isolate);
1068 1069 1070 1071 1072 1073 1074 1075 1076 1077

    // Run some warmup code to help ignoring existing log entries.
    CompileRun(
        "function warmUp(a) {"
        " let b = () => 1;"
        " return function(c) { return a+b+c; };"
        "};"
        "warmUp(1)(2);"
        "(function warmUpEndMarkerFunction(){})();");

1078 1079
    const char* source_text =
        "function lazyNotExecutedFunction() { return 'lazy' };"
1080 1081 1082 1083 1084 1085 1086 1087 1088
        "function lazyFunction() { "
        "  function lazyInnerFunction() { return 'lazy' };"
        "  return lazyInnerFunction;"
        "};"
        "let innerFn = lazyFunction();"
        "innerFn();"
        "(function eagerFunction(){ return 'eager' })();"
        "function Foo() { this.foo = function(){}; };"
        "let i = new Foo(); i.foo();";
1089 1090 1091 1092
    CompileRun(source_text);

    logger.StopLogging();

1093
    // Ignore all the log entries that happened before warmup
1094
    const char* start =
1095 1096
        logger.FindLine("function,first-execution", "warmUpEndMarkerFunction");
    CHECK_NOT_NULL(start);
1097
    const char* pairs[][2] = {
1098 1099 1100
        // Create a new script
        {"script,create", nullptr},
        {"script-details", nullptr},
1101 1102 1103 1104 1105 1106 1107 1108 1109 1110 1111 1112 1113 1114
        // Step 1: parsing top-level script, preparsing functions
        {"function,preparse-", ",lazyNotExecutedFunction"},
        // Missing name for preparsing lazyInnerFunction
        // {"function,preparse-", nullptr},
        {"function,preparse-", ",lazyFunction"},
        {"function,full-parse,", ",eagerFunction"},
        {"function,preparse-", ",Foo"},
        // Missing name for inner preparsing of Foo.foo
        // {"function,preparse-", nullptr},
        // Missing name for top-level script.
        {"function,parse-script,", nullptr},

        // Step 2: compiling top-level script and eager functions
        // - Compiling script without name.
1115
        {"function,compile,", nullptr},
1116 1117 1118 1119 1120 1121 1122
        {"function,compile,", ",eagerFunction"},

        // Step 3: start executing script
        // Step 4. - lazy parse, lazy compiling and execute skipped functions
        //         - execute eager functions.
        {"function,parse-function,", ",lazyFunction"},
        {"function,compile-lazy,", ",lazyFunction"},
1123
        {"function,first-execution,", ",lazyFunction"},
1124 1125 1126

        {"function,parse-function,", ",lazyInnerFunction"},
        {"function,compile-lazy,", ",lazyInnerFunction"},
1127 1128 1129
        {"function,first-execution,", ",lazyInnerFunction"},

        {"function,first-execution,", ",eagerFunction"},
1130 1131 1132

        {"function,parse-function,", ",Foo"},
        {"function,compile-lazy,", ",Foo"},
1133 1134
        {"function,first-execution,", ",Foo"},

1135 1136
        {"function,parse-function,", ",Foo.foo"},
        {"function,compile-lazy,", ",Foo.foo"},
1137
        {"function,first-execution,", ",Foo.foo"},
1138 1139
    };
    logger.FindLogLines(pairs, arraysize(pairs), start);
1140 1141 1142 1143
  }
  i::FLAG_log_function_events = false;
  isolate->Dispose();
}