test-trace-event.cc 13 KB
Newer Older
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24
// Copyright 2015 the V8 project authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include <stdlib.h>
#include <string.h>

#include "src/v8.h"

#include "test/cctest/cctest.h"

#include "src/tracing/trace-event.h"

#define GET_TRACE_OBJECTS_LIST platform.GetMockTraceObjects()

#define GET_TRACE_OBJECT(Index) GET_TRACE_OBJECTS_LIST->at(Index)


struct MockTraceObject {
  char phase;
  std::string name;
  uint64_t id;
  uint64_t bind_id;
  int num_args;
  unsigned int flags;
25
  int64_t timestamp;
26
  MockTraceObject(char phase, std::string name, uint64_t id, uint64_t bind_id,
27
                  int num_args, int flags, int64_t timestamp)
28 29 30 31 32
      : phase(phase),
        name(name),
        id(id),
        bind_id(bind_id),
        num_args(num_args),
33 34
        flags(flags),
        timestamp(timestamp) {}
35 36
};

37
typedef std::vector<MockTraceObject*> MockTraceObjectList;
38

39
class MockTracingController : public v8::TracingController {
40
 public:
41
  MockTracingController() = default;
42
  ~MockTracingController() override {
43
    for (size_t i = 0; i < trace_object_list_.size(); ++i) {
44 45
      delete trace_object_list_[i];
    }
46
    trace_object_list_.clear();
47 48
  }

49 50 51 52 53 54 55
  uint64_t AddTraceEvent(
      char phase, const uint8_t* category_enabled_flag, const char* name,
      const char* scope, uint64_t id, uint64_t bind_id, int num_args,
      const char** arg_names, const uint8_t* arg_types,
      const uint64_t* arg_values,
      std::unique_ptr<v8::ConvertableToTraceFormat>* arg_convertables,
      unsigned int flags) override {
56 57 58 59 60 61 62 63 64 65 66 67 68 69
    return AddTraceEventWithTimestamp(
        phase, category_enabled_flag, name, scope, id, bind_id, num_args,
        arg_names, arg_types, arg_values, arg_convertables, flags, 0);
  }

  uint64_t AddTraceEventWithTimestamp(
      char phase, const uint8_t* category_enabled_flag, const char* name,
      const char* scope, uint64_t id, uint64_t bind_id, int num_args,
      const char** arg_names, const uint8_t* arg_types,
      const uint64_t* arg_values,
      std::unique_ptr<v8::ConvertableToTraceFormat>* arg_convertables,
      unsigned int flags, int64_t timestamp) override {
    MockTraceObject* to = new MockTraceObject(
        phase, std::string(name), id, bind_id, num_args, flags, timestamp);
70
    trace_object_list_.push_back(to);
71 72 73 74 75 76 77
    return 0;
  }

  void UpdateTraceEventDuration(const uint8_t* category_enabled_flag,
                                const char* name, uint64_t handle) override {}

  const uint8_t* GetCategoryGroupEnabled(const char* name) override {
78
    if (strncmp(name, "v8-cat", 6)) {
79 80 81 82 83 84 85 86
      static uint8_t no = 0;
      return &no;
    } else {
      static uint8_t yes = 0x7;
      return &yes;
    }
  }

87
  MockTraceObjectList* GetMockTraceObjects() { return &trace_object_list_; }
88 89

 private:
90
  MockTraceObjectList trace_object_list_;
91 92 93 94

  DISALLOW_COPY_AND_ASSIGN(MockTracingController);
};

95
class MockTracingPlatform : public TestPlatform {
96
 public:
97 98 99 100
  MockTracingPlatform() {
    // Now that it's completely constructed, make this the current platform.
    i::V8::SetPlatformForTesting(this);
  }
101
  ~MockTracingPlatform() override = default;
102 103 104 105 106 107 108 109 110 111 112

  v8::TracingController* GetTracingController() override {
    return &tracing_controller_;
  }

  MockTraceObjectList* GetMockTraceObjects() {
    return tracing_controller_.GetMockTraceObjects();
  }

 private:
  MockTracingController tracing_controller_;
113 114 115 116
};


TEST(TraceEventDisabledCategory) {
117
  MockTracingPlatform platform;
118 119 120 121

  // Disabled category, will not add events.
  TRACE_EVENT_BEGIN0("cat", "e1");
  TRACE_EVENT_END0("cat", "e1");
122
  CHECK(GET_TRACE_OBJECTS_LIST->empty());
123 124 125 126
}


TEST(TraceEventNoArgs) {
127
  MockTracingPlatform platform;
128 129 130 131 132

  // Enabled category will add 2 events.
  TRACE_EVENT_BEGIN0("v8-cat", "e1");
  TRACE_EVENT_END0("v8-cat", "e1");

133
  CHECK_EQ(2, GET_TRACE_OBJECTS_LIST->size());
134 135 136 137 138 139 140 141 142 143 144
  CHECK_EQ('B', GET_TRACE_OBJECT(0)->phase);
  CHECK_EQ("e1", GET_TRACE_OBJECT(0)->name);
  CHECK_EQ(0, GET_TRACE_OBJECT(0)->num_args);

  CHECK_EQ('E', GET_TRACE_OBJECT(1)->phase);
  CHECK_EQ("e1", GET_TRACE_OBJECT(1)->name);
  CHECK_EQ(0, GET_TRACE_OBJECT(1)->num_args);
}


TEST(TraceEventWithOneArg) {
145
  MockTracingPlatform platform;
146 147 148 149 150 151

  TRACE_EVENT_BEGIN1("v8-cat", "e1", "arg1", 42);
  TRACE_EVENT_END1("v8-cat", "e1", "arg1", 42);
  TRACE_EVENT_BEGIN1("v8-cat", "e2", "arg1", "abc");
  TRACE_EVENT_END1("v8-cat", "e2", "arg1", "abc");

152
  CHECK_EQ(4, GET_TRACE_OBJECTS_LIST->size());
153 154 155 156 157 158 159 160 161

  CHECK_EQ(1, GET_TRACE_OBJECT(0)->num_args);
  CHECK_EQ(1, GET_TRACE_OBJECT(1)->num_args);
  CHECK_EQ(1, GET_TRACE_OBJECT(2)->num_args);
  CHECK_EQ(1, GET_TRACE_OBJECT(3)->num_args);
}


TEST(TraceEventWithTwoArgs) {
162
  MockTracingPlatform platform;
163 164 165 166 167 168

  TRACE_EVENT_BEGIN2("v8-cat", "e1", "arg1", 42, "arg2", "abc");
  TRACE_EVENT_END2("v8-cat", "e1", "arg1", 42, "arg2", "abc");
  TRACE_EVENT_BEGIN2("v8-cat", "e2", "arg1", "abc", "arg2", 43);
  TRACE_EVENT_END2("v8-cat", "e2", "arg1", "abc", "arg2", 43);

169
  CHECK_EQ(4, GET_TRACE_OBJECTS_LIST->size());
170 171 172 173 174 175 176 177 178

  CHECK_EQ(2, GET_TRACE_OBJECT(0)->num_args);
  CHECK_EQ(2, GET_TRACE_OBJECT(1)->num_args);
  CHECK_EQ(2, GET_TRACE_OBJECT(2)->num_args);
  CHECK_EQ(2, GET_TRACE_OBJECT(3)->num_args);
}


TEST(ScopedTraceEvent) {
179
  MockTracingPlatform platform;
180 181 182

  { TRACE_EVENT0("v8-cat", "e"); }

183
  CHECK_EQ(1, GET_TRACE_OBJECTS_LIST->size());
184 185 186 187
  CHECK_EQ(0, GET_TRACE_OBJECT(0)->num_args);

  { TRACE_EVENT1("v8-cat", "e1", "arg1", "abc"); }

188
  CHECK_EQ(2, GET_TRACE_OBJECTS_LIST->size());
189 190 191 192
  CHECK_EQ(1, GET_TRACE_OBJECT(1)->num_args);

  { TRACE_EVENT2("v8-cat", "e1", "arg1", "abc", "arg2", 42); }

193
  CHECK_EQ(3, GET_TRACE_OBJECTS_LIST->size());
194 195 196 197 198
  CHECK_EQ(2, GET_TRACE_OBJECT(2)->num_args);
}


TEST(TestEventWithFlow) {
199
  MockTracingPlatform platform;
200 201 202 203 204 205 206 207 208 209 210 211

  static uint64_t bind_id = 21;
  {
    TRACE_EVENT_WITH_FLOW0("v8-cat", "f1", bind_id, TRACE_EVENT_FLAG_FLOW_OUT);
  }
  {
    TRACE_EVENT_WITH_FLOW0(
        "v8-cat", "f2", bind_id,
        TRACE_EVENT_FLAG_FLOW_IN | TRACE_EVENT_FLAG_FLOW_OUT);
  }
  { TRACE_EVENT_WITH_FLOW0("v8-cat", "f3", bind_id, TRACE_EVENT_FLAG_FLOW_IN); }

212
  CHECK_EQ(3, GET_TRACE_OBJECTS_LIST->size());
213 214 215 216 217 218 219 220 221 222 223
  CHECK_EQ(bind_id, GET_TRACE_OBJECT(0)->bind_id);
  CHECK_EQ(TRACE_EVENT_FLAG_FLOW_OUT, GET_TRACE_OBJECT(0)->flags);
  CHECK_EQ(bind_id, GET_TRACE_OBJECT(1)->bind_id);
  CHECK_EQ(TRACE_EVENT_FLAG_FLOW_IN | TRACE_EVENT_FLAG_FLOW_OUT,
           GET_TRACE_OBJECT(1)->flags);
  CHECK_EQ(bind_id, GET_TRACE_OBJECT(2)->bind_id);
  CHECK_EQ(TRACE_EVENT_FLAG_FLOW_IN, GET_TRACE_OBJECT(2)->flags);
}


TEST(TestEventWithId) {
224
  MockTracingPlatform platform;
225 226 227 228 229

  static uint64_t event_id = 21;
  TRACE_EVENT_ASYNC_BEGIN0("v8-cat", "a1", event_id);
  TRACE_EVENT_ASYNC_END0("v8-cat", "a1", event_id);

230
  CHECK_EQ(2, GET_TRACE_OBJECTS_LIST->size());
231 232 233 234 235
  CHECK_EQ(TRACE_EVENT_PHASE_ASYNC_BEGIN, GET_TRACE_OBJECT(0)->phase);
  CHECK_EQ(event_id, GET_TRACE_OBJECT(0)->id);
  CHECK_EQ(TRACE_EVENT_PHASE_ASYNC_END, GET_TRACE_OBJECT(1)->phase);
  CHECK_EQ(event_id, GET_TRACE_OBJECT(1)->id);
}
236 237

TEST(TestEventInContext) {
238
  MockTracingPlatform platform;
239 240 241 242 243 244 245

  static uint64_t isolate_id = 0x20151021;
  {
    TRACE_EVENT_SCOPED_CONTEXT("v8-cat", "Isolate", isolate_id);
    TRACE_EVENT0("v8-cat", "e");
  }

246
  CHECK_EQ(3, GET_TRACE_OBJECTS_LIST->size());
247 248 249 250 251 252 253 254 255
  CHECK_EQ(TRACE_EVENT_PHASE_ENTER_CONTEXT, GET_TRACE_OBJECT(0)->phase);
  CHECK_EQ("Isolate", GET_TRACE_OBJECT(0)->name);
  CHECK_EQ(isolate_id, GET_TRACE_OBJECT(0)->id);
  CHECK_EQ(TRACE_EVENT_PHASE_COMPLETE, GET_TRACE_OBJECT(1)->phase);
  CHECK_EQ("e", GET_TRACE_OBJECT(1)->name);
  CHECK_EQ(TRACE_EVENT_PHASE_LEAVE_CONTEXT, GET_TRACE_OBJECT(2)->phase);
  CHECK_EQ("Isolate", GET_TRACE_OBJECT(2)->name);
  CHECK_EQ(isolate_id, GET_TRACE_OBJECT(2)->id);
}
256 257 258 259 260 261 262 263 264 265

TEST(TestEventWithTimestamp) {
  MockTracingPlatform platform;

  TRACE_EVENT_INSTANT_WITH_TIMESTAMP0("v8-cat", "0arg",
                                      TRACE_EVENT_SCOPE_GLOBAL, 1729);
  TRACE_EVENT_INSTANT_WITH_TIMESTAMP1("v8-cat", "1arg",
                                      TRACE_EVENT_SCOPE_GLOBAL, 4104, "val", 1);
  TRACE_EVENT_MARK_WITH_TIMESTAMP2("v8-cat", "mark", 13832, "a", 1, "b", 2);

266 267 268 269 270 271
  TRACE_EVENT_COPY_NESTABLE_ASYNC_BEGIN_WITH_TIMESTAMP0("v8-cat", "begin", 5,
                                                        20683);
  TRACE_EVENT_COPY_NESTABLE_ASYNC_END_WITH_TIMESTAMP0("v8-cat", "end", 5,
                                                      32832);

  CHECK_EQ(5, GET_TRACE_OBJECTS_LIST->size());
272 273 274 275 276 277 278 279 280

  CHECK_EQ(1729, GET_TRACE_OBJECT(0)->timestamp);
  CHECK_EQ(0, GET_TRACE_OBJECT(0)->num_args);

  CHECK_EQ(4104, GET_TRACE_OBJECT(1)->timestamp);
  CHECK_EQ(1, GET_TRACE_OBJECT(1)->num_args);

  CHECK_EQ(13832, GET_TRACE_OBJECT(2)->timestamp);
  CHECK_EQ(2, GET_TRACE_OBJECT(2)->num_args);
281 282 283

  CHECK_EQ(20683, GET_TRACE_OBJECT(3)->timestamp);
  CHECK_EQ(32832, GET_TRACE_OBJECT(4)->timestamp);
284
}
285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309

TEST(BuiltinsIsTraceCategoryEnabled) {
  CcTest::InitializeVM();
  MockTracingPlatform platform;

  v8::Isolate* isolate = CcTest::isolate();
  v8::HandleScope handle_scope(isolate);
  LocalContext env;

  v8::Local<v8::Object> binding = env->GetExtrasBindingObject();
  CHECK(!binding.IsEmpty());

  auto undefined = v8::Undefined(isolate);
  auto isTraceCategoryEnabled =
      binding->Get(env.local(), v8_str("isTraceCategoryEnabled"))
          .ToLocalChecked()
          .As<v8::Function>();

  {
    // Test with an enabled category
    v8::Local<v8::Value> argv[] = {v8_str("v8-cat")};
    auto result = isTraceCategoryEnabled->Call(env.local(), undefined, 1, argv)
                      .ToLocalChecked()
                      .As<v8::Boolean>();

310
    CHECK(result->BooleanValue(isolate));
311 312 313 314 315 316 317 318 319
  }

  {
    // Test with a disabled category
    v8::Local<v8::Value> argv[] = {v8_str("cat")};
    auto result = isTraceCategoryEnabled->Call(env.local(), undefined, 1, argv)
                      .ToLocalChecked()
                      .As<v8::Boolean>();

320
    CHECK(!result->BooleanValue(isolate));
321 322 323 324 325 326 327 328 329
  }

  {
    // Test with an enabled utf8 category
    v8::Local<v8::Value> argv[] = {v8_str("v8-cat\u20ac")};
    auto result = isTraceCategoryEnabled->Call(env.local(), undefined, 1, argv)
                      .ToLocalChecked()
                      .As<v8::Boolean>();

330
    CHECK(result->BooleanValue(isolate));
331 332 333 334 335 336 337 338 339
  }
}

TEST(BuiltinsTrace) {
  CcTest::InitializeVM();
  MockTracingPlatform platform;

  v8::Isolate* isolate = CcTest::isolate();
  v8::HandleScope handle_scope(isolate);
340
  v8::Local<v8::Context> context = isolate->GetCurrentContext();
341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363
  LocalContext env;

  v8::Local<v8::Object> binding = env->GetExtrasBindingObject();
  CHECK(!binding.IsEmpty());

  auto undefined = v8::Undefined(isolate);
  auto trace = binding->Get(env.local(), v8_str("trace"))
                   .ToLocalChecked()
                   .As<v8::Function>();

  // Test with disabled category
  {
    v8::Local<v8::String> category = v8_str("cat");
    v8::Local<v8::String> name = v8_str("name");
    v8::Local<v8::Value> argv[] = {
        v8::Integer::New(isolate, 'b'),                // phase
        category, name, v8::Integer::New(isolate, 0),  // id
        undefined                                      // data
    };
    auto result = trace->Call(env.local(), undefined, 5, argv)
                      .ToLocalChecked()
                      .As<v8::Boolean>();

364
    CHECK(!result->BooleanValue(isolate));
365 366 367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382
    CHECK_EQ(0, GET_TRACE_OBJECTS_LIST->size());
  }

  // Test with enabled category
  {
    v8::Local<v8::String> category = v8_str("v8-cat");
    v8::Local<v8::String> name = v8_str("name");
    v8::Local<v8::Object> data = v8::Object::New(isolate);
    data->Set(context, v8_str("foo"), v8_str("bar")).FromJust();
    v8::Local<v8::Value> argv[] = {
        v8::Integer::New(isolate, 'b'),                  // phase
        category, name, v8::Integer::New(isolate, 123),  // id
        data                                             // data arg
    };
    auto result = trace->Call(env.local(), undefined, 5, argv)
                      .ToLocalChecked()
                      .As<v8::Boolean>();

383
    CHECK(result->BooleanValue(isolate));
384 385 386 387 388 389 390 391 392 393 394 395 396 397 398 399 400 401 402 403 404 405 406
    CHECK_EQ(1, GET_TRACE_OBJECTS_LIST->size());

    CHECK_EQ(123, GET_TRACE_OBJECT(0)->id);
    CHECK_EQ('b', GET_TRACE_OBJECT(0)->phase);
    CHECK_EQ("name", GET_TRACE_OBJECT(0)->name);
    CHECK_EQ(1, GET_TRACE_OBJECT(0)->num_args);
  }

  // Test with enabled utf8 category
  {
    v8::Local<v8::String> category = v8_str("v8-cat\u20ac");
    v8::Local<v8::String> name = v8_str("name\u20ac");
    v8::Local<v8::Object> data = v8::Object::New(isolate);
    data->Set(context, v8_str("foo"), v8_str("bar")).FromJust();
    v8::Local<v8::Value> argv[] = {
        v8::Integer::New(isolate, 'b'),                  // phase
        category, name, v8::Integer::New(isolate, 123),  // id
        data                                             // data arg
    };
    auto result = trace->Call(env.local(), undefined, 5, argv)
                      .ToLocalChecked()
                      .As<v8::Boolean>();

407
    CHECK(result->BooleanValue(isolate));
408 409 410 411 412 413 414 415
    CHECK_EQ(2, GET_TRACE_OBJECTS_LIST->size());

    CHECK_EQ(123, GET_TRACE_OBJECT(1)->id);
    CHECK_EQ('b', GET_TRACE_OBJECT(1)->phase);
    CHECK_EQ("name\u20ac", GET_TRACE_OBJECT(1)->name);
    CHECK_EQ(1, GET_TRACE_OBJECT(1)->num_args);
  }
}