1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19 package org.eclipse.jetty.monitor;
20
21 import java.lang.management.ManagementFactory;
22 import java.lang.management.ThreadMXBean;
23 import java.util.ArrayList;
24 import java.util.Collections;
25 import java.util.Comparator;
26 import java.util.HashMap;
27 import java.util.HashSet;
28 import java.util.Iterator;
29 import java.util.List;
30 import java.util.Map;
31 import java.util.Set;
32
33 import org.eclipse.jetty.monitor.thread.ThreadMonitorException;
34 import org.eclipse.jetty.monitor.thread.ThreadMonitorInfo;
35 import org.eclipse.jetty.util.annotation.ManagedObject;
36 import org.eclipse.jetty.util.component.AbstractLifeCycle;
37 import org.eclipse.jetty.util.component.Dumpable;
38 import org.eclipse.jetty.util.log.Log;
39 import org.eclipse.jetty.util.log.Logger;
40
41 @ManagedObject("Busy Thread Monitor")
42 public class ThreadMonitor extends AbstractLifeCycle implements Runnable
43 {
44 private static final Logger LOG = Log.getLogger(ThreadMonitor.class);
45
46 private int _scanInterval;
47 private int _logInterval;
48 private int _busyThreshold;
49 private int _logThreshold;
50 private int _stackDepth;
51 private int _trailLength;
52
53 private ThreadMXBean _threadBean;
54
55 private Thread _runner;
56 private Logger _logger;
57 private volatile boolean _done = true;
58 private Dumpable _dumpable;
59
60 private Map<Long,ThreadMonitorInfo> _monitorInfo;
61
62
63
64
65
66
67
68 public ThreadMonitor() throws Exception
69 {
70 this(5000);
71 }
72
73
74
75
76
77
78
79
80 public ThreadMonitor(int intervalMs) throws Exception
81 {
82 this(intervalMs, 95);
83 }
84
85
86
87
88
89
90
91
92
93 public ThreadMonitor(int intervalMs, int threshold) throws Exception
94 {
95 this(intervalMs, threshold, 3);
96 }
97
98
99
100
101
102
103
104
105
106
107 public ThreadMonitor(int intervalMs, int threshold, int depth) throws Exception
108 {
109 this(intervalMs, threshold, depth, 3);
110 }
111
112
113
114
115
116
117
118
119
120
121
122 public ThreadMonitor(int intervalMs, int threshold, int depth, int trail) throws Exception
123 {
124 _scanInterval = intervalMs;
125 _busyThreshold = threshold;
126 _stackDepth = depth;
127 _trailLength = trail;
128
129 _logger = Log.getLogger(ThreadMonitor.class.getName());
130 _monitorInfo = new HashMap<Long, ThreadMonitorInfo>();
131
132 init();
133 }
134
135
136
137
138
139
140
141 public int getScanInterval()
142 {
143 return _scanInterval;
144 }
145
146
147
148
149
150
151
152 public void setScanInterval(int ms)
153 {
154 _scanInterval = ms;
155 }
156
157
158
159
160
161
162
163 public int getLogInterval()
164 {
165 return _logInterval;
166 }
167
168
169
170
171
172
173
174 public void setLogInterval(int ms)
175 {
176 _logInterval = ms;
177 }
178
179
180
181
182
183
184
185 public int getBusyThreshold()
186 {
187 return _busyThreshold;
188 }
189
190
191
192
193
194
195
196 public void setBusyThreshold(int percent)
197 {
198 _busyThreshold = percent;
199 }
200
201
202
203
204
205
206
207 public int getLogThreshold()
208 {
209 return _logThreshold;
210 }
211
212
213
214
215
216
217
218 public void setLogThreshold(int percent)
219 {
220 _logThreshold = percent;
221 }
222
223
224
225
226
227
228
229 public int getStackDepth()
230 {
231 return _stackDepth;
232 }
233
234
235
236
237
238
239
240 public void setStackDepth(int stackDepth)
241 {
242 _stackDepth = stackDepth;
243 }
244
245
246
247
248
249
250
251 public void setTrailLength(int trailLength)
252 {
253 _trailLength = trailLength;
254 }
255
256
257
258
259
260
261
262 public int getTrailLength()
263 {
264 return _trailLength;
265 }
266
267
268
269
270
271
272
273
274 public void logCpuUsage(int frequencyMs, int thresholdPercent)
275 {
276 setLogInterval(frequencyMs);
277 setLogThreshold(thresholdPercent);
278 }
279
280
281
282
283
284 public Dumpable getDumpable()
285 {
286 return _dumpable;
287 }
288
289
290
291
292
293 public void setDumpable(Dumpable dumpable)
294 {
295 _dumpable = dumpable;
296 }
297
298
299
300
301
302 public void doStart()
303 {
304 _done = false;
305
306 _runner = new Thread(this);
307 _runner.setDaemon(true);
308 _runner.start();
309
310 LOG.info("Thread Monitor started successfully");
311 }
312
313
314
315
316
317 public void doStop()
318 {
319 if (_runner != null)
320 {
321 _done = true;
322 try
323 {
324 _runner.join();
325 }
326 catch (InterruptedException ex) {}
327
328 _monitorInfo.clear();
329 }
330 }
331
332
333
334
335
336
337
338 protected long[] getAllThreadIds()
339 {
340 return _threadBean.getAllThreadIds();
341 }
342
343
344
345
346
347
348
349
350 protected long getThreadCpuTime(long id)
351 {
352 return _threadBean.getThreadCpuTime(id);
353 }
354
355
356
357
358
359 protected void init()
360 {
361 _threadBean = ManagementFactory.getThreadMXBean();
362 if (_threadBean.isThreadCpuTimeSupported())
363 {
364 _threadBean.setThreadCpuTimeEnabled(true);
365 }
366 }
367
368
369
370
371
372 public void run()
373 {
374
375 boolean repeat = false;
376 boolean scanNow, logNow;
377
378
379 long nextScanTime = System.currentTimeMillis();
380 long nextLogTime = nextScanTime + _logInterval;
381
382 while (!_done)
383 {
384 long currTime = System.currentTimeMillis();
385 scanNow = (currTime > nextScanTime);
386 logNow = (_logInterval > 0 && currTime > nextLogTime);
387 if (repeat || scanNow || logNow)
388 {
389 repeat = collectThreadInfo();
390 logThreadInfo(logNow);
391
392 if (scanNow)
393 {
394 nextScanTime = System.currentTimeMillis() + _scanInterval;
395 }
396 if (logNow)
397 {
398 nextLogTime = System.currentTimeMillis() + _logInterval;
399 }
400 }
401
402
403 if (!repeat)
404 {
405 try
406 {
407 Thread.sleep(100);
408 }
409 catch (InterruptedException ex)
410 {
411 LOG.ignore(ex);
412 }
413 }
414 }
415
416 }
417
418
419
420
421
422 private boolean collectThreadInfo()
423 {
424 boolean repeat = false;
425 try
426 {
427
428
429
430 Map<Thread,StackTraceElement[]> all = Thread.getAllStackTraces();
431
432 Set<Long> newOrUpdatedIds = new HashSet<Long>();
433
434 for (Map.Entry<Thread,StackTraceElement[]> entry : all.entrySet())
435 {
436 Thread thread = entry.getKey();
437 long threadId = thread.getId();
438
439
440 if (threadId == _runner.getId())
441 {
442 continue;
443 }
444
445 ThreadMonitorInfo currMonitorInfo = _monitorInfo.get(Long.valueOf(threadId));
446 if (currMonitorInfo == null)
447 {
448
449 currMonitorInfo = new ThreadMonitorInfo(thread);
450 currMonitorInfo.setStackTrace(entry.getValue());
451 currMonitorInfo.setCpuTime(getThreadCpuTime(threadId));
452 currMonitorInfo.setSampleTime(System.nanoTime());
453 _monitorInfo.put(Long.valueOf(threadId), currMonitorInfo);
454 }
455 else
456 {
457
458 currMonitorInfo.setStackTrace(entry.getValue());
459 currMonitorInfo.setCpuTime(getThreadCpuTime(threadId));
460 currMonitorInfo.setSampleTime(System.nanoTime());
461
462
463 int count = currMonitorInfo.getTraceCount();
464 if (count >= 0 && currMonitorInfo.isSpinning())
465 {
466
467 if (count < _trailLength)
468 {
469
470 currMonitorInfo.setTraceCount(count+1);
471 repeat = true;
472 continue;
473 }
474
475
476 currMonitorInfo.setSpinning(false);
477 currMonitorInfo.setTraceCount(-1);
478 }
479 if (currMonitorInfo.getCpuUtilization() > _busyThreshold)
480 {
481
482 StackTraceElement[] lastStackTrace = currMonitorInfo.getStackTrace();
483
484 if (lastStackTrace != null
485 && matchStackTraces(lastStackTrace, entry.getValue()))
486 {
487
488 currMonitorInfo.setSpinning(true);
489 if (count < 0)
490 {
491
492
493
494 currMonitorInfo.setTraceCount(0);
495 repeat = (_trailLength > 0);
496 }
497 }
498 }
499 }
500 newOrUpdatedIds.add(Long.valueOf(threadId));
501 }
502
503
504 Iterator<Long> iter = _monitorInfo.keySet().iterator();
505 while (iter.hasNext())
506 {
507 Long id = iter.next();
508 if (!newOrUpdatedIds.contains(id))
509 iter.remove();
510 }
511 newOrUpdatedIds.clear();
512 }
513 catch (Exception ex)
514 {
515 LOG.debug(ex);
516 }
517 return repeat;
518 }
519
520
521 protected void logThreadInfo(boolean logAll)
522 {
523 if (_monitorInfo.size() > 0)
524 {
525
526 long[] running = getAllThreadIds();
527 List<ThreadMonitorInfo> all = new ArrayList<ThreadMonitorInfo>();
528 for (int idx=0; idx<running.length; idx++)
529 {
530 ThreadMonitorInfo info = _monitorInfo.get(running[idx]);
531 if (info != null)
532 {
533 all.add(info);
534 }
535 }
536
537
538 Collections.sort(all, new Comparator<ThreadMonitorInfo>()
539 {
540
541 public int compare(ThreadMonitorInfo info1, ThreadMonitorInfo info2)
542 {
543 return (int)Math.signum(info2.getCpuUtilization()-info1.getCpuUtilization());
544 }
545 });
546
547 String format = "Thread '%2$s'[%3$s,id:%1$d,cpu:%4$.2f%%]%5$s";
548
549
550
551 boolean spinning=false;
552 for (ThreadMonitorInfo info : all)
553 {
554 if (logAll && info.getCpuUtilization() > _logThreshold
555 || info.isSpinning() && info.getTraceCount() == 0)
556 {
557 String message = String.format(format,
558 info.getThreadId(), info.getThreadName(),
559 info.getThreadState(), info.getCpuUtilization(),
560 info.isSpinning() ? " SPINNING" : "");
561 _logger.info(message);
562 spinning=true;
563 }
564 }
565
566
567 if (spinning && _dumpable!=null)
568 {
569 System.err.println(_dumpable.dump());
570 }
571
572
573 for (ThreadMonitorInfo info : all)
574 {
575 if (info.isSpinning() && info.getTraceCount() >= 0)
576 {
577 String message = String.format(format,
578 info.getThreadId(), info.getThreadName(),
579 info.getThreadState(), info.getCpuUtilization(),
580 " STACK TRACE");
581 _logger.warn(new ThreadMonitorException(message, info.getStackTrace()));
582 }
583 }
584 }
585 }
586
587
588
589
590
591
592
593
594
595 private boolean matchStackTraces(StackTraceElement[] lastStackTrace, StackTraceElement[] stackTrace)
596 {
597 boolean match = true;
598 int count = Math.min(_stackDepth, Math.min(lastStackTrace.length, stackTrace.length));
599
600 for (int idx=0; idx < count; idx++)
601 {
602 if (!stackTrace[idx].equals(lastStackTrace[idx]))
603 {
604 match = false;
605 break;
606 }
607 }
608 return match;
609 }
610 }