blob: e970214e6e698693e6ada17daadcf5765c8e84a7 (
plain) (
blame)
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
|
// Copyright Vespa.ai. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
#pragma once
#include <vespa/vespalib/stllike/string.h>
#include <vespa/vespalib/util/static_string.h>
#include <vespa/vespalib/util/time.h>
#include <memory>
namespace vespalib { class Slime; }
namespace vespalib::slime { struct Cursor; }
namespace vespalib::slime { struct Inserter; }
namespace search::engine {
class Clock {
public:
virtual ~Clock() = default;
virtual vespalib::steady_time now() const = 0;
};
class SteadyClock : public Clock {
public:
vespalib::steady_time now() const override;
};
class CountingClock : public Clock {
public:
CountingClock(int64_t start, int64_t increment) : _increment(increment), _nextTime(start) { }
vespalib::steady_time now() const override {
int64_t prev = _nextTime;
_nextTime += _increment;
return vespalib::steady_time(vespalib::duration(prev));
}
private:
const int64_t _increment;
mutable int64_t _nextTime;
};
class RelativeTime {
public:
RelativeTime(std::unique_ptr<Clock> clock);
vespalib::steady_time timeOfDawn() const { return _start; }
vespalib::duration timeSinceDawn() const { return _clock->now() - _start; }
vespalib::steady_time now() const { return _clock->now(); }
private:
vespalib::steady_time _start;
std::unique_ptr<Clock> _clock;
};
class Trace;
// Helper class used to inject subtraces back into a parent trace
class LazyTraceInserter
{
private:
Trace &_parent;
vespalib::stringref _name;
vespalib::slime::Cursor *_entry;
std::unique_ptr<vespalib::slime::Inserter> _thread_inserter;
vespalib::slime::Cursor &get_entry();
vespalib::slime::Inserter &get_thread_inserter();
public:
LazyTraceInserter(search::engine::Trace &parent, vespalib::StaticStringView name) noexcept;
~LazyTraceInserter();
void handle_nested(const search::engine::Trace &nested_trace);
void handle_thread(const search::engine::Trace &thread_trace);
};
/**
* Used for adding traces to a request. Acquire a new Cursor for everytime you want to trace something.
* Note that it is not thread safe. All use of any cursor aquired must be thread safe.
*/
class Trace
{
private:
struct ctor_tag {};
public:
using Cursor = vespalib::slime::Cursor;
Trace(const Trace &parent, ctor_tag);
Trace(const RelativeTime & relativeTime, uint32_t traceLevel);
~Trace();
/**
* Will add start timestamp if level is high enough
* @param level
*/
void start(int level, bool useUTC=true);
/**
* Will give you a trace entry. It will also add a timestamp relative to the creation of the trace.
* @param name
* @return a Cursor to use for further tracing.
*/
Cursor & createCursor(vespalib::stringref name);
Cursor * maybeCreateCursor(uint32_t level, vespalib::stringref name);
/**
* Will add a simple 'event' string. It will also add a timestamp relative to the creation of the trace.
* @param level require for actually add the trace.
* @param event
*/
void addEvent(uint32_t level, vespalib::stringref event);
/**
* Will compute and and a final duration timing.
*/
void done();
vespalib::string toString() const;
bool hasTrace() const { return static_cast<bool>(_trace); }
Cursor & getRoot() const { return root(); }
Cursor & getTraces() const { return traces(); }
vespalib::Slime & getSlime() const { return slime(); }
bool shouldTrace(uint32_t level) const { return level <= _level; }
uint32_t getLevel() const { return _level; }
Trace & setLevel(uint32_t level) { _level = level; return *this; }
Trace &match_profile_depth(int32_t depth) { _match_profile_depth = depth; return *this; }
Trace &first_phase_profile_depth(int32_t depth) { _first_phase_profile_depth = depth; return *this; }
Trace &second_phase_profile_depth(int32_t depth) { _second_phase_profile_depth = depth; return *this; }
Trace &profile_depth(int32_t depth) {
match_profile_depth(depth);
first_phase_profile_depth(depth);
second_phase_profile_depth(depth);
return *this;
}
int32_t match_profile_depth() const { return _match_profile_depth; }
int32_t first_phase_profile_depth() const { return _first_phase_profile_depth; }
int32_t second_phase_profile_depth() const { return _second_phase_profile_depth; }
Trace make_trace() const { return Trace(*this, ctor_tag()); }
std::unique_ptr<Trace> make_trace_up() const { return std::make_unique<Trace>(*this, ctor_tag()); }
LazyTraceInserter make_inserter(vespalib::StaticStringView name) { return {*this, name}; }
private:
vespalib::Slime & slime() const {
if (!hasTrace()) {
constructObject();
}
return *_trace;
}
Cursor & root() const {
if (!hasTrace()) {
constructObject();
}
return *_root;
}
Cursor & traces() const {
if (!_traces) {
constructTraces();
}
return *_traces;
}
void constructObject() const;
void constructTraces() const;
void addTimeStamp(Cursor & trace);
mutable std::unique_ptr<vespalib::Slime> _trace;
mutable Cursor * _root;
mutable Cursor * _traces;
const RelativeTime & _relativeTime;
uint32_t _level;
int32_t _match_profile_depth;
int32_t _first_phase_profile_depth;
int32_t _second_phase_profile_depth;
};
}
|
