1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18 package org.tikv.common.log;
19
20 import com.google.gson.JsonArray;
21 import com.google.gson.JsonObject;
22 import java.math.BigInteger;
23 import java.text.SimpleDateFormat;
24 import java.util.ArrayList;
25 import java.util.HashMap;
26 import java.util.List;
27 import java.util.Map;
28 import java.util.Map.Entry;
29 import java.util.Random;
30 import org.slf4j.Logger;
31 import org.slf4j.LoggerFactory;
32
33 public class SlowLogImpl implements SlowLog {
34
35 private static final Logger logger = LoggerFactory.getLogger(SlowLogImpl.class);
36
37 private static final int MAX_SPAN_SIZE = 1024;
38
39 private static final Random random = new Random();
40
41 private final List<SlowLogSpan> slowLogSpans = new ArrayList<>();
42 private final HashMap<String, Object> fields = new HashMap<>();
43 private Throwable error = null;
44
45 private final long startMS;
46
47
48
49 private final long startNS;
50
51 private final long slowThresholdMS;
52
53 private final long traceId;
54
55 private long durationMS;
56
57 public SlowLogImpl(long slowThresholdMS) {
58 this.startMS = System.currentTimeMillis();
59 this.startNS = System.nanoTime();
60 this.slowThresholdMS = slowThresholdMS;
61 this.traceId = random.nextLong();
62 }
63
64 @Override
65 public synchronized SlowLogSpan start(String name) {
66 SlowLogSpan slowLogSpan = new SlowLogSpanImpl(name, startMS, startNS);
67 if (slowLogSpans.size() < MAX_SPAN_SIZE) {
68 slowLogSpans.add(slowLogSpan);
69 }
70 slowLogSpan.start();
71 return slowLogSpan;
72 }
73
74 @Override
75 public long getTraceId() {
76 return traceId;
77 }
78
79 @Override
80 public long getThresholdMS() {
81 return slowThresholdMS;
82 }
83
84 @Override
85 public void setError(Throwable err) {
86 this.error = err;
87 }
88
89 @Override
90 public SlowLog withFields(Map<String, Object> fields) {
91 this.fields.putAll(fields);
92 return this;
93 }
94
95 @Override
96 public Object getField(String key) {
97 return fields.get(key);
98 }
99
100 @Override
101 public void log() {
102 recordTime();
103 if (error != null || timeExceeded()) {
104 SimpleDateFormat dateFormat = new SimpleDateFormat("HH:mm:ss.SSS");
105 logger.warn(
106 String.format(
107 "A request spent %s ms. start=%s, end=%s, SlowLog:%s",
108 durationMS,
109 dateFormat.format(startMS),
110 dateFormat.format(startMS + durationMS),
111 getSlowLogJson().toString()));
112 }
113 }
114
115 private void recordTime() {
116 long currentNS = System.nanoTime();
117 durationMS = (currentNS - startNS) / 1_000_000;
118 }
119
120 boolean timeExceeded() {
121 return slowThresholdMS >= 0 && durationMS > slowThresholdMS;
122 }
123
124 JsonObject getSlowLogJson() {
125 JsonObject jsonObject = new JsonObject();
126
127 jsonObject.addProperty("trace_id", toUnsignedBigInteger(traceId));
128
129 if (error != null) {
130 jsonObject.addProperty("error", error.getMessage());
131 }
132
133 JsonArray jsonArray = new JsonArray();
134 for (SlowLogSpan slowLogSpan : slowLogSpans) {
135 jsonArray.add(slowLogSpan.toJsonElement());
136 }
137 jsonObject.add("spans", jsonArray);
138
139 for (Entry<String, Object> entry : fields.entrySet()) {
140 Object value = entry.getValue();
141 if (value instanceof List) {
142 JsonArray field = new JsonArray();
143 for (Object o : (List<?>) value) {
144 field.add(o.toString());
145 }
146 jsonObject.add(entry.getKey(), field);
147 } else if (value instanceof Map) {
148 JsonObject field = new JsonObject();
149 for (Entry<?, ?> e : ((Map<?, ?>) value).entrySet()) {
150 field.addProperty(e.getKey().toString(), e.getValue().toString());
151 }
152 jsonObject.add(entry.getKey(), field);
153 } else {
154 jsonObject.addProperty(entry.getKey(), value.toString());
155 }
156 }
157
158 return jsonObject;
159 }
160
161 static BigInteger toUnsignedBigInteger(long i) {
162 if (i >= 0) {
163 return BigInteger.valueOf(i);
164 } else {
165 long withoutSign = i & ~(1L << 63);
166
167 return (BigInteger.valueOf(1)).shiftLeft(63).add(BigInteger.valueOf(withoutSign));
168 }
169 }
170 }