Skip to content

Commit d354ffc

Browse files
iosmanthusiosmanthus
authored
[to #556] slowlog: attach cluster_id and pd_addresses to slow log properties (#557)
1 parent 9798382 commit d354ffc

File tree

6 files changed

+125
-14
lines changed

6 files changed

+125
-14
lines changed

‎src/main/java/org/tikv/common/PDClient.java‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -840,4 +840,12 @@ private Metapb.Region decodeRegion(Metapb.Region region) {
840840

841841
return builder.build();
842842
}
843+
844+
public long getClusterId() {
845+
return header.getClusterId();
846+
}
847+
848+
public List<URI> getPdAddrs() {
849+
return pdAddrs;
850+
}
843851
}

‎src/main/java/org/tikv/common/log/SlowLog.java‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,7 +17,11 @@
1717

1818
package org.tikv.common.log;
1919

20+
import com.google.common.collect.ImmutableMap;
21+
import java.util.Map;
22+
2023
public interface SlowLog {
24+
2125
SlowLogSpan start(String name);
2226

2327
long getTraceId();
@@ -26,5 +30,11 @@ public interface SlowLog {
2630

2731
void setError(Throwable err);
2832

33+
SlowLog withFields(Map<String, Object> fields);
34+
35+
default SlowLog withField(String key, Object value) {
36+
return withFields(ImmutableMap.of(key, value));
37+
}
38+
2939
void log();
3040
}

‎src/main/java/org/tikv/common/log/SlowLogEmptyImpl.java‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,8 @@
1717

1818
package org.tikv.common.log;
1919

20+
import java.util.Map;
21+
2022
public class SlowLogEmptyImpl implements SlowLog {
2123
public static final SlowLogEmptyImpl INSTANCE = new SlowLogEmptyImpl();
2224

@@ -40,6 +42,11 @@ public long getThresholdMS() {
4042
@Override
4143
public void setError(Throwable err) {}
4244

45+
@Override
46+
public SlowLog withFields(Map<String, Object> fields) {
47+
return this;
48+
}
49+
4350
@Override
4451
public void log() {}
4552
}

‎src/main/java/org/tikv/common/log/SlowLogImpl.java‎

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,19 +22,24 @@
2222
import java.math.BigInteger;
2323
import java.text.SimpleDateFormat;
2424
import java.util.ArrayList;
25+
import java.util.HashMap;
2526
import java.util.List;
27+
import java.util.Map;
28+
import java.util.Map.Entry;
2629
import java.util.Random;
2730
import org.slf4j.Logger;
2831
import org.slf4j.LoggerFactory;
2932

3033
public class SlowLogImpl implements SlowLog {
34+
3135
private static final Logger logger = LoggerFactory.getLogger(SlowLogImpl.class);
3236

3337
private static final int MAX_SPAN_SIZE = 1024;
3438

3539
private static final Random random = new Random();
3640

3741
private final List<SlowLogSpan> slowLogSpans = new ArrayList<>();
42+
private final HashMap<String, Object> fields = new HashMap<>();
3843
private Throwable error = null;
3944

4045
private final long startMS;
@@ -81,6 +86,12 @@ public void setError(Throwable err) {
8186
this.error = err;
8287
}
8388

89+
@Override
90+
public SlowLog withFields(Map<String, Object> fields) {
91+
this.fields.putAll(fields);
92+
return this;
93+
}
94+
8495
@Override
8596
public void log() {
8697
recordTime();
@@ -120,6 +131,25 @@ JsonObject getSlowLogJson() {
120131
}
121132
jsonObject.add("spans", jsonArray);
122133

134+
for (Entry<String, Object> entry : fields.entrySet()) {
135+
Object value = entry.getValue();
136+
if (value instanceof List) {
137+
JsonArray field = new JsonArray();
138+
for (Object o : (List<?>) value) {
139+
field.add(o.toString());
140+
}
141+
jsonObject.add(entry.getKey(), field);
142+
} else if (value instanceof Map) {
143+
JsonObject field = new JsonObject();
144+
for (Entry<?, ?> e : ((Map<?, ?>) value).entrySet()) {
145+
field.addProperty(e.getKey().toString(), e.getValue().toString());
146+
}
147+
jsonObject.add(entry.getKey(), field);
148+
} else {
149+
jsonObject.addProperty(entry.getKey(), value.toString());
150+
}
151+
}
152+
123153
return jsonObject;
124154
}
125155

‎src/main/java/org/tikv/raw/RawKVClient.java‎

Lines changed: 47 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -17,13 +17,31 @@
1717

1818
package org.tikv.raw;
1919

20-
import static org.tikv.common.util.ClientUtils.*;
20+
import static org.tikv.common.util.ClientUtils.appendBatches;
21+
import static org.tikv.common.util.ClientUtils.genUUID;
22+
import static org.tikv.common.util.ClientUtils.getBatches;
23+
import static org.tikv.common.util.ClientUtils.getTasks;
24+
import static org.tikv.common.util.ClientUtils.getTasksWithOutput;
25+
import static org.tikv.common.util.ClientUtils.groupKeysByRegion;
2126

2227
import com.google.protobuf.ByteString;
2328
import io.prometheus.client.Counter;
2429
import io.prometheus.client.Histogram;
25-
import java.util.*;
26-
import java.util.concurrent.*;
30+
import java.net.URI;
31+
import java.util.ArrayList;
32+
import java.util.HashMap;
33+
import java.util.Iterator;
34+
import java.util.LinkedList;
35+
import java.util.List;
36+
import java.util.Map;
37+
import java.util.Objects;
38+
import java.util.Optional;
39+
import java.util.Queue;
40+
import java.util.concurrent.ExecutionException;
41+
import java.util.concurrent.ExecutorCompletionService;
42+
import java.util.concurrent.ExecutorService;
43+
import java.util.concurrent.Future;
44+
import java.util.concurrent.TimeUnit;
2745
import java.util.stream.Collectors;
2846
import org.slf4j.Logger;
2947
import org.slf4j.LoggerFactory;
@@ -44,10 +62,19 @@
4462
import org.tikv.common.region.RegionStoreClient;
4563
import org.tikv.common.region.RegionStoreClient.RegionStoreClientBuilder;
4664
import org.tikv.common.region.TiRegion;
47-
import org.tikv.common.util.*;
65+
import org.tikv.common.util.BackOffFunction;
66+
import org.tikv.common.util.BackOffer;
67+
import org.tikv.common.util.Batch;
68+
import org.tikv.common.util.ConcreteBackOffer;
69+
import org.tikv.common.util.DeleteRange;
70+
import org.tikv.common.util.HistogramUtils;
71+
import org.tikv.common.util.Pair;
72+
import org.tikv.common.util.ScanOption;
4873
import org.tikv.kvproto.Kvrpcpb.KvPair;
4974

5075
public class RawKVClient implements RawKVClientBase {
76+
private final long clusterId;
77+
private final List<URI> pdAddresses;
5178
private final TiSession tiSession;
5279
private final RegionStoreClientBuilder clientBuilder;
5380
private final TiConfiguration conf;
@@ -95,6 +122,12 @@ public RawKVClient(TiSession session, RegionStoreClientBuilder clientBuilder) {
95122
this.batchScanThreadPool = session.getThreadPoolForBatchScan();
96123
this.deleteRangeThreadPool = session.getThreadPoolForDeleteRange();
97124
this.atomicForCAS = conf.isEnableAtomicForCAS();
125+
this.clusterId = session.getPDClient().getClusterId();
126+
this.pdAddresses = session.getPDClient().getPdAddrs();
127+
}
128+
129+
private SlowLog withClusterInfo(SlowLog logger) {
130+
return logger.withField("cluster_id", clusterId).withField("pd_addresses", pdAddresses);
98131
}
99132

100133
@Override
@@ -110,7 +143,7 @@ public void put(ByteString key, ByteString value, long ttl) {
110143
String label = "client_raw_put";
111144
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
112145

113-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVWriteSlowLogInMS());
146+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVWriteSlowLogInMS()));
114147
SlowLogSpan span = slowLog.start("put");
115148
span.addProperty("key", KeyUtils.formatBytesUTF8(key));
116149

@@ -172,7 +205,7 @@ public void compareAndSet(
172205
String label = "client_raw_compare_and_set";
173206
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
174207

175-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVWriteSlowLogInMS());
208+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVWriteSlowLogInMS()));
176209
SlowLogSpan span = slowLog.start("putIfAbsent");
177210
span.addProperty("key", KeyUtils.formatBytesUTF8(key));
178211

@@ -211,7 +244,7 @@ public void batchPut(Map<ByteString, ByteString> kvPairs, long ttl) {
211244
String label = "client_raw_batch_put";
212245
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
213246

214-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVBatchWriteSlowLogInMS());
247+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVBatchWriteSlowLogInMS()));
215248
SlowLogSpan span = slowLog.start("batchPut");
216249
span.addProperty("keySize", String.valueOf(kvPairs.size()));
217250

@@ -237,7 +270,7 @@ public Optional<ByteString> get(ByteString key) {
237270
String label = "client_raw_get";
238271
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
239272

240-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVReadSlowLogInMS());
273+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVReadSlowLogInMS()));
241274
SlowLogSpan span = slowLog.start("get");
242275
span.addProperty("key", KeyUtils.formatBytesUTF8(key));
243276

@@ -270,7 +303,7 @@ public Optional<ByteString> get(ByteString key) {
270303
public List<KvPair> batchGet(List<ByteString> keys) {
271304
String label = "client_raw_batch_get";
272305
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
273-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVBatchReadSlowLogInMS());
306+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVBatchReadSlowLogInMS()));
274307
SlowLogSpan span = slowLog.start("batchGet");
275308
span.addProperty("keySize", String.valueOf(keys.size()));
276309
ConcreteBackOffer backOffer =
@@ -295,7 +328,7 @@ public List<KvPair> batchGet(List<ByteString> keys) {
295328
public void batchDelete(List<ByteString> keys) {
296329
String label = "client_raw_batch_delete";
297330
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
298-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVBatchWriteSlowLogInMS());
331+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVBatchWriteSlowLogInMS()));
299332
SlowLogSpan span = slowLog.start("batchDelete");
300333
span.addProperty("keySize", String.valueOf(keys.size()));
301334
ConcreteBackOffer backOffer =
@@ -320,7 +353,7 @@ public void batchDelete(List<ByteString> keys) {
320353
public Optional<Long> getKeyTTL(ByteString key) {
321354
String label = "client_raw_get_key_ttl";
322355
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
323-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVReadSlowLogInMS());
356+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVReadSlowLogInMS()));
324357
SlowLogSpan span = slowLog.start("getKeyTTL");
325358
span.addProperty("key", KeyUtils.formatBytesUTF8(key));
326359
ConcreteBackOffer backOffer =
@@ -428,7 +461,7 @@ public List<KvPair> scan(ByteString startKey, ByteString endKey, int limit) {
428461
public List<KvPair> scan(ByteString startKey, ByteString endKey, int limit, boolean keyOnly) {
429462
String label = "client_raw_scan";
430463
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
431-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVScanSlowLogInMS());
464+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVScanSlowLogInMS()));
432465
SlowLogSpan span = slowLog.start("scan");
433466
span.addProperty("startKey", KeyUtils.formatBytesUTF8(startKey));
434467
span.addProperty("endKey", KeyUtils.formatBytesUTF8(endKey));
@@ -473,7 +506,7 @@ public List<KvPair> scan(ByteString startKey, ByteString endKey) {
473506
public List<KvPair> scan(ByteString startKey, ByteString endKey, boolean keyOnly) {
474507
String label = "client_raw_scan_without_limit";
475508
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
476-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVScanSlowLogInMS());
509+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVScanSlowLogInMS()));
477510
SlowLogSpan span = slowLog.start("scan");
478511
span.addProperty("startKey", KeyUtils.formatBytesUTF8(startKey));
479512
span.addProperty("endKey", KeyUtils.formatBytesUTF8(endKey));
@@ -539,7 +572,7 @@ public List<KvPair> scanPrefix(ByteString prefixKey, boolean keyOnly) {
539572
public void delete(ByteString key) {
540573
String label = "client_raw_delete";
541574
Histogram.Timer requestTimer = RAW_REQUEST_LATENCY.labels(label).startTimer();
542-
SlowLog slowLog = new SlowLogImpl(conf.getRawKVWriteSlowLogInMS());
575+
SlowLog slowLog = withClusterInfo(new SlowLogImpl(conf.getRawKVWriteSlowLogInMS()));
543576
SlowLogSpan span = slowLog.start("delete");
544577
span.addProperty("key", KeyUtils.formatBytesUTF8(key));
545578
ConcreteBackOffer backOffer =

‎src/test/java/org/tikv/common/log/SlowLogImplTest.java‎

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,8 +17,11 @@
1717

1818
package org.tikv.common.log;
1919

20+
import com.google.common.collect.ImmutableList;
21+
import com.google.common.collect.ImmutableMap;
2022
import com.google.gson.JsonArray;
2123
import com.google.gson.JsonObject;
24+
import java.util.concurrent.atomic.AtomicInteger;
2225
import org.junit.Assert;
2326
import org.junit.Test;
2427

@@ -63,4 +66,24 @@ public void testUnsignedLong() {
6366
Assert.assertEquals("18446744073709551615", SlowLogImpl.toUnsignedBigInteger(-1L).toString());
6467
Assert.assertEquals("18446744073709551614", SlowLogImpl.toUnsignedBigInteger(-2L).toString());
6568
}
69+
70+
@Test
71+
public void testWithFields() throws InterruptedException {
72+
SlowLogImpl slowLog = new SlowLogImpl(1);
73+
slowLog
74+
.withField("key0", "value0")
75+
.withField("key1", ImmutableList.of("value0", "value1"))
76+
.withField("key2", ImmutableMap.of("key3", "value3"));
77+
78+
JsonObject object = slowLog.getSlowLogJson();
79+
Assert.assertEquals("value0", object.get("key0").getAsString());
80+
81+
AtomicInteger i = new AtomicInteger();
82+
object
83+
.get("key1")
84+
.getAsJsonArray()
85+
.forEach(e -> Assert.assertEquals("value" + (i.getAndIncrement()), e.getAsString()));
86+
87+
Assert.assertEquals("value3", object.get("key2").getAsJsonObject().get("key3").getAsString());
88+
}
6689
}

0 commit comments

Comments
 (0)