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
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
|
// Copyright Vespa.ai. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
package com.yahoo.search.statistics;
import com.yahoo.collections.TinyIdentitySet;
import com.yahoo.search.statistics.TimeTracker.Activity;
import com.yahoo.search.statistics.TimeTracker.SearcherTimer;
import java.util.LinkedHashMap;
import java.util.Map;
import java.util.Set;
import static com.yahoo.search.statistics.TimeTracker.Activity.*;
/**
* A collection of TimeTracker instances.
*
* @author Steinar Knutsen
*/
// This class may need a lot of restructuring as actual needs are mapped out.
public class ElapsedTime {
// An identity set is used to make it safe to do multiple merges. This may happen if
// user calls Result.mergeWith() and Result.mergeWithAfterFill() on the same result
// with the same result as an argument too. This is slightly pathological, but better
// safe than sorry. It also covers in SearchHandler where the same Execution instance
// is used for search and fill.
/** A map used as a set to store the time track of all the Execution instances for a Result */
private final Set<TimeTracker> tracks = new TinyIdentitySet<>(8);
public void add(TimeTracker track) {
tracks.add(track);
}
private long fetcher(Activity toFetch, TimeTracker fetchFrom) {
return switch (toFetch) {
case SEARCH -> fetchFrom.searchTime();
case FILL -> fetchFrom.fillTime();
case PING -> fetchFrom.pingTime();
};
}
/**
* Give an estimate on how much of the time tracked by this
* instance was used fetching document contents. This will
* by definition be smaller than last() - first().
*/
public long weightedFillTime() {
return weightedTime(FILL);
}
private long weightedTime(Activity kind) {
long total = 0L;
long elapsed = 0L;
long first = Long.MAX_VALUE;
long last = 0L;
if (tracks.isEmpty()) {
return 0L;
}
for (TimeTracker track : tracks) {
total += track.totalTime();
elapsed += fetcher(kind, track);
last = Math.max(last, track.last());
first = Math.min(first, track.first());
}
if (total == 0L) {
return 0L;
} else {
return ((last - first) * elapsed) / total;
}
}
private long absoluteTime(Activity kind) {
long elapsed = 0L;
if (tracks.isEmpty()) {
return 0L;
}
for (TimeTracker track : tracks) {
elapsed += fetcher(kind, track);
}
return elapsed;
}
/**
* Total amount of time spent in all threads for this Execution while
* fetching document contents, or preparing to fetch them.
*/
public long fillTime() {
return absoluteTime(FILL);
}
/**
* Total amount of time spent for this ElapsedTime instance.
*/
public long totalTime() {
long total = 0L;
for (TimeTracker track : tracks) {
total += track.totalTime();
}
return total;
}
/**
* Give a relative estimate on how much of the time tracked by this
* instance was used searching. This will
* by definition be smaller than last() - first().
*/
public long weightedSearchTime() {
return weightedTime(SEARCH);
}
/**
* Total amount of time spent in all threads for this Execution while
* searching or waiting for (a) backend(s) doing (a) search(es).
*/
public long searchTime() {
return absoluteTime(SEARCH);
}
/**
* Total amount of time spent in all threads for this Execution while
* pinging, or preparing to ping, a backend.
*/
public long pingTime() {
return absoluteTime(PING);
}
/**
* Give a relative estimate on how much of the time tracked by this
* instance was used pinging backends. This will
* by definition be smaller than last() - first().
*/
public long weightedPingTime() {
return weightedTime(PING);
}
/**
* Time stamp of start of the first event registered.
*/
public long first() {
long first = Long.MAX_VALUE;
for (TimeTracker track : tracks) {
first = Math.min(first, track.first());
}
return first;
}
/**
* Time stamp of the end the last event registered.
*/
public long last() {
long last = 0L;
for (TimeTracker track : tracks) {
last = Math.max(last, track.last());
}
return last;
}
public void merge(ElapsedTime other) {
for (TimeTracker t : other.tracks) {
add(t);
}
}
/**
* The time of the start of the first document fill requested.
*/
public long firstFill() {
long first = Long.MAX_VALUE;
if (tracks.isEmpty()) {
return 0L;
}
for (TimeTracker t : tracks) {
long candidate = t.firstFill();
if (candidate == 0L) {
continue;
}
first = Math.min(first, t.firstFill());
}
return first;
}
/*
* Tell whether time use per searcher is available.
*/
public boolean hasDetailedData() {
for (TimeTracker t : tracks) {
if (t.searcherTracking() != null) {
return true;
}
}
return false;
}
public String detailedReport() {
Map<String, TimeTracker.SearcherTimer> raw = new LinkedHashMap<>();
StringBuilder report = new StringBuilder();
int preLen;
report.append("Time use per searcher: ");
for (TimeTracker t : tracks) {
if (t.searcherTracking() == null) {
continue;
}
SearcherTimer[] searchers = t.searcherTracking();
for (SearcherTimer s : searchers) {
SearcherTimer sum;
if (raw.containsKey(s.getName())) {
sum = raw.get(s.getName());
} else {
sum = new SearcherTimer(s.getName());
raw.put(s.getName(), sum);
}
sum.merge(s);
}
}
preLen = report.length();
for (TimeTracker.SearcherTimer value : raw.values()) {
if (report.length() > preLen) {
report.append(",\n ");
}
report.append(value.toString());
}
report.append(".");
return report.toString();
}
}
|
