summaryrefslogtreecommitdiffstats
path: root/common/TraceEvent.cpp
blob: e4a87e317cbe8201405461358b2e3d1b9f6f8423 (plain)
1
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
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
/* -*- Mode: C++; tab-width: 4; indent-tabs-mode: nil; c-basic-offset: 4; fill-column: 100 -*- */
/*
 * This Source Code Form is subject to the terms of the Mozilla Public
 * License, v. 2.0. If a copy of the MPL was not distributed with this
 * file, You can obtain one at http://mozilla.org/MPL/2.0/.
 */

// To build a freestanding test executable for just Tracevent:
// clang++ -Wall -Wextra -DTEST_TRACEEVENT_EXE TraceEvent.cpp -o TraceEvent -pthread

#include <cassert>
#include <mutex>
#include <sstream>

#include "TraceEvent.hpp"

std::atomic<bool> TraceEvent::recordingOn(false);

thread_local int TraceEvent::threadLocalNesting = 0; // level of overlapped zones

static std::mutex mutex;

void TraceEvent::emitInstantEvent(const std::string& name, const std::string& argsOrEmpty)
{
    if (!recordingOn)
        return;

    emitOneRecording("{"
                     "\"name\":\""
                     + name
                     + "\","
                       "\"ph\":\"i\""
                     + ",\"ts\":"
                     + std::to_string(std::chrono::duration_cast<std::chrono::microseconds>(
                              std::chrono::system_clock::now().time_since_epoch())
                              .count())
                     + ","
                       "\"pid\":"
                     + std::to_string(getpid())
                     + ","
                       "\"tid\":"
                     + std::to_string(getThreadId())
                     + (argsOrEmpty.length() == 0 ? "" : ",\"args\":" + argsOrEmpty)
                     + "}"
                     // We add a trailing comma and newline, it is up to the code that handles these "recordings"
                     // (outputs them into a JSON array) to remove the final comma before adding the terminating
                     // ']'.
                       ",\n");
}

void TraceEvent::startRecording()
{
    recordingOn = true;
    threadLocalNesting = 0;
}

void TraceEvent::stopRecording() { recordingOn = false; }

void ProfileZone::emitRecording()
{
    if (!recordingOn)
        return;

    auto now = std::chrono::system_clock::now();

    // Generate a single "Complete Event" (type X)
    auto duration = now - _createTime;

    std::string recordingData(
        "{"
        "\"name\":\""
        + std::string(_name)
        + "\","
          "\"ph\":\"X\","
          "\"ts\":"
        + std::to_string(std::chrono::duration_cast<std::chrono::microseconds>(
                             _createTime.time_since_epoch())
                             .count())
        + ","
          "\"dur\":"
        + std::to_string(std::chrono::duration_cast<std::chrono::microseconds>(duration).count())
        + ","
          "\"pid\":"
        + std::to_string(_pid)
        + ","
          "\"tid\":"
        + std::to_string(getThreadId())
        + (_args.length() == 0 ? "" : ",\"args\":" + _args)
        + "},");
    std::lock_guard<std::mutex> guard(mutex);
    emitOneRecording(recordingData);
}

#ifdef TEST_TRACEEVENT_EXE

#include <iostream>
#include <thread>

void TraceEvent::emitOneRecording(const std::string &recording)
{
    std::cout << "  " << recording;
}

int main(int, char**)
{
    std::cout << "[\n";

    TraceEvent::startRecording();

    {
        ProfileZone b("first block");

        for (auto n = 0; n < 100000000; n++)
        {
            volatile auto x = n * 42;
            (void)x;
        }
    }

    std::thread t1([]() {
        ProfileZone b("thread t1");

        for (auto n = 0; n < 400000000; n++)
        {
            volatile auto x = n * 42;
            (void)x;
        }
    });

    std::thread t2([]() {
        ProfileZone b("thread t2");

        for (auto n = 0; n < 400000000; n++)
        {
            auto x = n * 42ll;
            if (n % 50000000 == 0)
                TraceEvent::emitInstantEvent("instant t2." + std::to_string(x));
        }
    });

    std::thread t3([]() {
        ProfileZone b("thread t3", { { "foo", "bar"} } );

        for (auto n = 0; n < 400000000; n++)
        {
            auto x = n * 42ll;
            if (n % 50000000 == 0)
                TraceEvent::emitInstantEvent("instant t3." + std::to_string(x));
        }
    });

    {
        ProfileZone b("second block");

        for (auto n = 0; n < 300000000; n++)
        {
            auto x = n * 42ll;
            if (n % 50000000 == 0)
                TraceEvent::emitInstantEvent("instant m." + std::to_string(x));
        }
    }

    t1.join();
    t2.join();
    t3.join();

    // Intentional misuse: overlapping ProfileZones. Will generate "Incorrect ProfileZone nesting" messages.
    auto p1 = new ProfileZone("p1");
    auto p2 = new ProfileZone("p2");
    delete p1;
    delete p2;

    // Add a dummy integer last in the array to avoid incorrect JSON syntax
    std::cout << "  0\n";
    std::cout << "]\n";

    return 0;
}

#endif

/* vim:set shiftwidth=4 softtabstop=4 expandtab: */