View Javadoc

1   //
2   //  ========================================================================
3   //  Copyright (c) 1995-2015 Mort Bay Consulting Pty. Ltd.
4   //  ------------------------------------------------------------------------
5   //  All rights reserved. This program and the accompanying materials
6   //  are made available under the terms of the Eclipse Public License v1.0
7   //  and Apache License v2.0 which accompanies this distribution.
8   //
9   //      The Eclipse Public License is available at
10  //      http://www.eclipse.org/legal/epl-v10.html
11  //
12  //      The Apache License v2.0 is available at
13  //      http://www.opensource.org/licenses/apache2.0.php
14  //
15  //  You may elect to redistribute this code under either of these licenses.
16  //  ========================================================================
17  //
18  
19  package org.eclipse.jetty.server.handler;
20  
21  import java.io.IOException;
22  import java.util.concurrent.Future;
23  import java.util.concurrent.TimeoutException;
24  import java.util.concurrent.atomic.AtomicInteger;
25  import java.util.concurrent.atomic.AtomicLong;
26  import java.util.concurrent.atomic.AtomicReference;
27  
28  import javax.servlet.AsyncEvent;
29  import javax.servlet.AsyncListener;
30  import javax.servlet.ServletException;
31  import javax.servlet.http.HttpServletRequest;
32  import javax.servlet.http.HttpServletResponse;
33  import javax.sql.rowset.BaseRowSet;
34  
35  import org.eclipse.jetty.http.HttpStatus;
36  import org.eclipse.jetty.server.AsyncContextEvent;
37  import org.eclipse.jetty.server.Handler;
38  import org.eclipse.jetty.server.HttpChannelState;
39  import org.eclipse.jetty.server.Request;
40  import org.eclipse.jetty.server.Response;
41  import org.eclipse.jetty.util.FutureCallback;
42  import org.eclipse.jetty.util.annotation.ManagedAttribute;
43  import org.eclipse.jetty.util.annotation.ManagedObject;
44  import org.eclipse.jetty.util.annotation.ManagedOperation;
45  import org.eclipse.jetty.util.component.Graceful;
46  import org.eclipse.jetty.util.statistic.CounterStatistic;
47  import org.eclipse.jetty.util.statistic.SampleStatistic;
48  
49  @ManagedObject("Request Statistics Gathering")
50  public class StatisticsHandler extends HandlerWrapper implements Graceful
51  {
52      private final AtomicLong _statsStartedAt = new AtomicLong();
53  
54      private final CounterStatistic _requestStats = new CounterStatistic();
55      private final SampleStatistic _requestTimeStats = new SampleStatistic();
56      private final CounterStatistic _dispatchedStats = new CounterStatistic();
57      private final SampleStatistic _dispatchedTimeStats = new SampleStatistic();
58      private final CounterStatistic _asyncWaitStats = new CounterStatistic();
59  
60      private final AtomicInteger _asyncDispatches = new AtomicInteger();
61      private final AtomicInteger _expires = new AtomicInteger();
62  
63      private final AtomicInteger _responses1xx = new AtomicInteger();
64      private final AtomicInteger _responses2xx = new AtomicInteger();
65      private final AtomicInteger _responses3xx = new AtomicInteger();
66      private final AtomicInteger _responses4xx = new AtomicInteger();
67      private final AtomicInteger _responses5xx = new AtomicInteger();
68      private final AtomicLong _responsesTotalBytes = new AtomicLong();
69  
70      private final AtomicReference<FutureCallback> _shutdown=new AtomicReference<>();
71      
72      private final AsyncListener _onCompletion = new AsyncListener()
73      {
74          @Override
75          public void onTimeout(AsyncEvent event) throws IOException
76          {
77              _expires.incrementAndGet();
78          }
79          
80          @Override
81          public void onStartAsync(AsyncEvent event) throws IOException
82          {
83              event.getAsyncContext().addListener(this);
84          }
85          
86          @Override
87          public void onError(AsyncEvent event) throws IOException
88          {
89          }
90  
91          @Override
92          public void onComplete(AsyncEvent event) throws IOException
93          {
94              HttpChannelState state = ((AsyncContextEvent)event).getHttpChannelState();
95  
96              Request request = state.getBaseRequest();
97              final long elapsed = System.currentTimeMillis()-request.getTimeStamp();
98  
99              long d=_requestStats.decrement();
100             _requestTimeStats.set(elapsed);
101 
102             updateResponse(request);
103 
104             _asyncWaitStats.decrement();
105             
106             // If we have no more dispatches, should we signal shutdown?
107             if (d==0)
108             {
109                 FutureCallback shutdown = _shutdown.get();
110                 if (shutdown!=null)
111                     shutdown.succeeded();
112             }   
113         }
114     };
115 
116     /**
117      * Resets the current request statistics.
118      */
119     @ManagedOperation(value="resets statistics", impact="ACTION")
120     public void statsReset()
121     {
122         _statsStartedAt.set(System.currentTimeMillis());
123 
124         _requestStats.reset();
125         _requestTimeStats.reset();
126         _dispatchedStats.reset();
127         _dispatchedTimeStats.reset();
128         _asyncWaitStats.reset();
129 
130         _asyncDispatches.set(0);
131         _expires.set(0);
132         _responses1xx.set(0);
133         _responses2xx.set(0);
134         _responses3xx.set(0);
135         _responses4xx.set(0);
136         _responses5xx.set(0);
137         _responsesTotalBytes.set(0L);
138     }
139 
140     @Override
141     public void handle(String path, Request baseRequest, HttpServletRequest request, HttpServletResponse response) throws IOException, ServletException
142     {
143         _dispatchedStats.increment();
144 
145         final long start;
146         HttpChannelState state = baseRequest.getHttpChannelState();
147         if (state.isInitial())
148         {
149             // new request
150             _requestStats.increment();
151             start = baseRequest.getTimeStamp();
152         }
153         else
154         {
155             // resumed request
156             start = System.currentTimeMillis();
157             _asyncDispatches.incrementAndGet();
158         }
159 
160         try
161         {
162             Handler handler = getHandler();
163             if (handler!=null && _shutdown.get()==null && isStarted())
164                 handler.handle(path, baseRequest, request, response);
165             else
166             {
167                 baseRequest.setHandled(true);
168                 response.sendError(HttpStatus.SERVICE_UNAVAILABLE_503);
169             }
170         }
171         finally
172         {
173             final long now = System.currentTimeMillis();
174             final long dispatched=now-start;
175 
176             _dispatchedStats.decrement();
177             _dispatchedTimeStats.set(dispatched);
178 
179             if (state.isSuspended())
180             {
181                 if (state.isInitial())
182                 {
183                     state.addListener(_onCompletion);
184                     _asyncWaitStats.increment();
185                 }
186             }
187             else if (state.isInitial())
188             {
189                 long d=_requestStats.decrement();
190                 _requestTimeStats.set(dispatched);
191                 updateResponse(baseRequest);
192                 
193                 // If we have no more dispatches, should we signal shutdown?
194                 FutureCallback shutdown = _shutdown.get();
195                 if (shutdown!=null)
196                 {
197                     response.flushBuffer();
198                     if (d==0)
199                         shutdown.succeeded();
200                 }   
201             }
202             // else onCompletion will handle it.
203         }
204     }
205 
206     protected void updateResponse(Request request)
207     {
208         Response response = request.getResponse();
209         if (request.isHandled())
210         {
211             switch (response.getStatus() / 100)
212             {
213                 case 1:
214                     _responses1xx.incrementAndGet();
215                     break;
216                 case 2:
217                     _responses2xx.incrementAndGet();
218                     break;
219                 case 3:
220                     _responses3xx.incrementAndGet();
221                     break;
222                 case 4:
223                     _responses4xx.incrementAndGet();
224                     break;
225                 case 5:
226                     _responses5xx.incrementAndGet();
227                     break;
228                 default:
229                     break;
230             }
231         }
232         else
233             // will fall through to not found handler
234             _responses4xx.incrementAndGet();
235         _responsesTotalBytes.addAndGet(response.getContentCount());
236     }
237 
238     @Override
239     protected void doStart() throws Exception
240     {
241         _shutdown.set(null);
242         super.doStart();
243         statsReset();
244     }
245     
246 
247     @Override
248     protected void doStop() throws Exception
249     {
250         super.doStop();
251         FutureCallback shutdown = _shutdown.get();
252         if (shutdown!=null && !shutdown.isDone())
253             shutdown.failed(new TimeoutException());
254     }
255 
256     /**
257      * @return the number of requests handled by this handler
258      * since {@link #statsReset()} was last called, excluding
259      * active requests
260      * @see #getAsyncDispatches()
261      */
262     @ManagedAttribute("number of requests")
263     public int getRequests()
264     {
265         return (int)_requestStats.getTotal();
266     }
267 
268     /**
269      * @return the number of requests currently active.
270      * since {@link #statsReset()} was last called.
271      */
272     @ManagedAttribute("number of requests currently active")
273     public int getRequestsActive()
274     {
275         return (int)_requestStats.getCurrent();
276     }
277 
278     /**
279      * @return the maximum number of active requests
280      * since {@link #statsReset()} was last called.
281      */
282     @ManagedAttribute("maximum number of active requests")
283     public int getRequestsActiveMax()
284     {
285         return (int)_requestStats.getMax();
286     }
287 
288     /**
289      * @return the maximum time (in milliseconds) of request handling
290      * since {@link #statsReset()} was last called.
291      */
292     @ManagedAttribute("maximum time spend handling requests (in ms)")
293     public long getRequestTimeMax()
294     {
295         return _requestTimeStats.getMax();
296     }
297 
298     /**
299      * @return the total time (in milliseconds) of requests handling
300      * since {@link #statsReset()} was last called.
301      */
302     @ManagedAttribute("total time spend in all request handling (in ms)")
303     public long getRequestTimeTotal()
304     {
305         return _requestTimeStats.getTotal();
306     }
307 
308     /**
309      * @return the mean time (in milliseconds) of request handling
310      * since {@link #statsReset()} was last called.
311      * @see #getRequestTimeTotal()
312      * @see #getRequests()
313      */
314     @ManagedAttribute("mean time spent handling requests (in ms)")
315     public double getRequestTimeMean()
316     {
317         return _requestTimeStats.getMean();
318     }
319 
320     /**
321      * @return the standard deviation of time (in milliseconds) of request handling
322      * since {@link #statsReset()} was last called.
323      * @see #getRequestTimeTotal()
324      * @see #getRequests()
325      */
326     @ManagedAttribute("standard deviation for request handling (in ms)")
327     public double getRequestTimeStdDev()
328     {
329         return _requestTimeStats.getStdDev();
330     }
331 
332     /**
333      * @return the number of dispatches seen by this handler
334      * since {@link #statsReset()} was last called, excluding
335      * active dispatches
336      */
337     @ManagedAttribute("number of dispatches")
338     public int getDispatched()
339     {
340         return (int)_dispatchedStats.getTotal();
341     }
342 
343     /**
344      * @return the number of dispatches currently in this handler
345      * since {@link #statsReset()} was last called, including
346      * resumed requests
347      */
348     @ManagedAttribute("number of dispatches currently active")
349     public int getDispatchedActive()
350     {
351         return (int)_dispatchedStats.getCurrent();
352     }
353 
354     /**
355      * @return the max number of dispatches currently in this handler
356      * since {@link #statsReset()} was last called, including
357      * resumed requests
358      */
359     @ManagedAttribute("maximum number of active dispatches being handled")
360     public int getDispatchedActiveMax()
361     {
362         return (int)_dispatchedStats.getMax();
363     }
364 
365     /**
366      * @return the maximum time (in milliseconds) of request dispatch
367      * since {@link #statsReset()} was last called.
368      */
369     @ManagedAttribute("maximum time spend in dispatch handling")
370     public long getDispatchedTimeMax()
371     {
372         return _dispatchedTimeStats.getMax();
373     }
374 
375     /**
376      * @return the total time (in milliseconds) of requests handling
377      * since {@link #statsReset()} was last called.
378      */
379     @ManagedAttribute("total time spent in dispatch handling (in ms)")
380     public long getDispatchedTimeTotal()
381     {
382         return _dispatchedTimeStats.getTotal();
383     }
384 
385     /**
386      * @return the mean time (in milliseconds) of request handling
387      * since {@link #statsReset()} was last called.
388      * @see #getRequestTimeTotal()
389      * @see #getRequests()
390      */
391     @ManagedAttribute("mean time spent in dispatch handling (in ms)")
392     public double getDispatchedTimeMean()
393     {
394         return _dispatchedTimeStats.getMean();
395     }
396 
397     /**
398      * @return the standard deviation of time (in milliseconds) of request handling
399      * since {@link #statsReset()} was last called.
400      * @see #getRequestTimeTotal()
401      * @see #getRequests()
402      */
403     @ManagedAttribute("standard deviation for dispatch handling (in ms)")
404     public double getDispatchedTimeStdDev()
405     {
406         return _dispatchedTimeStats.getStdDev();
407     }
408 
409     /**
410      * @return the number of requests handled by this handler
411      * since {@link #statsReset()} was last called, including
412      * resumed requests
413      * @see #getAsyncDispatches()
414      */
415     @ManagedAttribute("total number of async requests")
416     public int getAsyncRequests()
417     {
418         return (int)_asyncWaitStats.getTotal();
419     }
420 
421     /**
422      * @return the number of requests currently suspended.
423      * since {@link #statsReset()} was last called.
424      */
425     @ManagedAttribute("currently waiting async requests")
426     public int getAsyncRequestsWaiting()
427     {
428         return (int)_asyncWaitStats.getCurrent();
429     }
430 
431     /**
432      * @return the maximum number of current suspended requests
433      * since {@link #statsReset()} was last called.
434      */
435     @ManagedAttribute("maximum number of waiting async requests")
436     public int getAsyncRequestsWaitingMax()
437     {
438         return (int)_asyncWaitStats.getMax();
439     }
440 
441     /**
442      * @return the number of requests that have been asynchronously dispatched
443      */
444     @ManagedAttribute("number of requested that have been asynchronously dispatched")
445     public int getAsyncDispatches()
446     {
447         return _asyncDispatches.get();
448     }
449 
450     /**
451      * @return the number of requests that expired while suspended.
452      * @see #getAsyncDispatches()
453      */
454     @ManagedAttribute("number of async requests requests that have expired")
455     public int getExpires()
456     {
457         return _expires.get();
458     }
459 
460     /**
461      * @return the number of responses with a 1xx status returned by this context
462      * since {@link #statsReset()} was last called.
463      */
464     @ManagedAttribute("number of requests with 1xx response status")
465     public int getResponses1xx()
466     {
467         return _responses1xx.get();
468     }
469 
470     /**
471      * @return the number of responses with a 2xx status returned by this context
472      * since {@link #statsReset()} was last called.
473      */
474     @ManagedAttribute("number of requests with 2xx response status")
475     public int getResponses2xx()
476     {
477         return _responses2xx.get();
478     }
479 
480     /**
481      * @return the number of responses with a 3xx status returned by this context
482      * since {@link #statsReset()} was last called.
483      */
484     @ManagedAttribute("number of requests with 3xx response status")
485     public int getResponses3xx()
486     {
487         return _responses3xx.get();
488     }
489 
490     /**
491      * @return the number of responses with a 4xx status returned by this context
492      * since {@link #statsReset()} was last called.
493      */
494     @ManagedAttribute("number of requests with 4xx response status")
495     public int getResponses4xx()
496     {
497         return _responses4xx.get();
498     }
499 
500     /**
501      * @return the number of responses with a 5xx status returned by this context
502      * since {@link #statsReset()} was last called.
503      */
504     @ManagedAttribute("number of requests with 5xx response status")
505     public int getResponses5xx()
506     {
507         return _responses5xx.get();
508     }
509 
510     /**
511      * @return the milliseconds since the statistics were started with {@link #statsReset()}.
512      */
513     @ManagedAttribute("time in milliseconds stats have been collected for")
514     public long getStatsOnMs()
515     {
516         return System.currentTimeMillis() - _statsStartedAt.get();
517     }
518 
519     /**
520      * @return the total bytes of content sent in responses
521      */
522     @ManagedAttribute("total number of bytes across all responses")
523     public long getResponsesBytesTotal()
524     {
525         return _responsesTotalBytes.get();
526     }
527 
528     public String toStatsHTML()
529     {
530         StringBuilder sb = new StringBuilder();
531 
532         sb.append("<h1>Statistics:</h1>\n");
533         sb.append("Statistics gathering started ").append(getStatsOnMs()).append("ms ago").append("<br />\n");
534 
535         sb.append("<h2>Requests:</h2>\n");
536         sb.append("Total requests: ").append(getRequests()).append("<br />\n");
537         sb.append("Active requests: ").append(getRequestsActive()).append("<br />\n");
538         sb.append("Max active requests: ").append(getRequestsActiveMax()).append("<br />\n");
539         sb.append("Total requests time: ").append(getRequestTimeTotal()).append("<br />\n");
540         sb.append("Mean request time: ").append(getRequestTimeMean()).append("<br />\n");
541         sb.append("Max request time: ").append(getRequestTimeMax()).append("<br />\n");
542         sb.append("Request time standard deviation: ").append(getRequestTimeStdDev()).append("<br />\n");
543 
544 
545         sb.append("<h2>Dispatches:</h2>\n");
546         sb.append("Total dispatched: ").append(getDispatched()).append("<br />\n");
547         sb.append("Active dispatched: ").append(getDispatchedActive()).append("<br />\n");
548         sb.append("Max active dispatched: ").append(getDispatchedActiveMax()).append("<br />\n");
549         sb.append("Total dispatched time: ").append(getDispatchedTimeTotal()).append("<br />\n");
550         sb.append("Mean dispatched time: ").append(getDispatchedTimeMean()).append("<br />\n");
551         sb.append("Max dispatched time: ").append(getDispatchedTimeMax()).append("<br />\n");
552         sb.append("Dispatched time standard deviation: ").append(getDispatchedTimeStdDev()).append("<br />\n");
553 
554 
555         sb.append("Total requests suspended: ").append(getAsyncRequests()).append("<br />\n");
556         sb.append("Total requests expired: ").append(getExpires()).append("<br />\n");
557         sb.append("Total requests resumed: ").append(getAsyncDispatches()).append("<br />\n");
558 
559         sb.append("<h2>Responses:</h2>\n");
560         sb.append("1xx responses: ").append(getResponses1xx()).append("<br />\n");
561         sb.append("2xx responses: ").append(getResponses2xx()).append("<br />\n");
562         sb.append("3xx responses: ").append(getResponses3xx()).append("<br />\n");
563         sb.append("4xx responses: ").append(getResponses4xx()).append("<br />\n");
564         sb.append("5xx responses: ").append(getResponses5xx()).append("<br />\n");
565         sb.append("Bytes sent total: ").append(getResponsesBytesTotal()).append("<br />\n");
566 
567         return sb.toString();
568 
569     }
570 
571     @Override
572     public Future<Void> shutdown()
573     {
574         FutureCallback shutdown=new FutureCallback(false);
575         _shutdown.compareAndSet(null,shutdown);
576         shutdown=_shutdown.get();
577         if (_dispatchedStats.getCurrent()==0)
578             shutdown.succeeded();
579         return shutdown;
580     }
581 }