1 /*
2  * Copyright (c) 1997, 2017, Oracle and/or its affiliates. All rights reserved.
3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4  *
5  * This code is free software; you can redistribute it and/or modify it
6  * under the terms of the GNU General Public License version 2 only, as
7  * published by the Free Software Foundation.
8  *
9  * This code is distributed in the hope that it will be useful, but WITHOUT
10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
12  * version 2 for more details (a copy is included in the LICENSE file that
13  * accompanied this code).
14  *
15  * You should have received a copy of the GNU General Public License version
16  * 2 along with this work; if not, write to the Free Software Foundation,
17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18  *
19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
20  * or visit www.oracle.com if you need additional information or have any
21  * questions.
22  *
23  */
24 
25 #ifndef SHARE_VM_UTILITIES_EVENTS_HPP
26 #define SHARE_VM_UTILITIES_EVENTS_HPP
27 
28 #include "memory/allocation.hpp"
29 #include "runtime/mutexLocker.hpp"
30 #include "runtime/thread.hpp"
31 #include "utilities/formatBuffer.hpp"
32 #include "utilities/vmError.hpp"
33 
34 // Events and EventMark provide interfaces to log events taking place in the vm.
35 // This facility is extremly useful for post-mortem debugging. The eventlog
36 // often provides crucial information about events leading up to the crash.
37 //
38 // Abstractly the logs can record whatever they way but normally they
39 // would record at least a timestamp and the current Thread, along
40 // with whatever data they need in a ring buffer.  Commonly fixed
41 // length text messages are recorded for simplicity but other
42 // strategies could be used.  Several logs are provided by default but
43 // new instances can be created as needed.
44 
45 // The base event log dumping class that is registered for dumping at
46 // crash time.  This is a very generic interface that is mainly here
47 // for completeness.  Normally the templated EventLogBase would be
48 // subclassed to provide different log types.
49 class EventLog : public CHeapObj<mtInternal> {
50   friend class Events;
51 
52  private:
53   EventLog* _next;
54 
next() const55   EventLog* next() const { return _next; }
56 
57  public:
58   // Automatically registers the log so that it will be printed during
59   // crashes.
60   EventLog();
61 
62   virtual void print_log_on(outputStream* out) = 0;
63 };
64 
65 
66 // A templated subclass of EventLog that provides basic ring buffer
67 // functionality.  Most event loggers should subclass this, possibly
68 // providing a more featureful log function if the existing copy
69 // semantics aren't appropriate.  The name is used as the label of the
70 // log when it is dumped during a crash.
71 template <class T> class EventLogBase : public EventLog {
72   template <class X> class EventRecord : public CHeapObj<mtInternal> {
73    public:
74     double  timestamp;
75     Thread* thread;
76     X       data;
77   };
78 
79  protected:
80   Mutex           _mutex;
81   const char*     _name;
82   int             _length;
83   int             _index;
84   int             _count;
85   EventRecord<T>* _records;
86 
87  public:
88   EventLogBase<T>(const char* name, int length = LogEventsBufferEntries):
89     _name(name),
90     _length(length),
91     _count(0),
92     _index(0),
93     _mutex(Mutex::event, name, false, Monitor::_safepoint_check_never) {
94     _records = new EventRecord<T>[length];
95   }
96 
fetch_timestamp()97   double fetch_timestamp() {
98     return os::elapsedTime();
99   }
100 
101   // move the ring buffer to next open slot and return the index of
102   // the slot to use for the current message.  Should only be called
103   // while mutex is held.
compute_log_index()104   int compute_log_index() {
105     int index = _index;
106     if (_count < _length) _count++;
107     _index++;
108     if (_index >= _length) _index = 0;
109     return index;
110   }
111 
should_log()112   bool should_log() {
113     // Don't bother adding new entries when we're crashing.  This also
114     // avoids mutating the ring buffer when printing the log.
115     return !VMError::fatal_error_in_progress();
116   }
117 
118   // Print the contents of the log
119   void print_log_on(outputStream* out);
120 
121  private:
122   void print_log_impl(outputStream* out);
123 
124   // Print a single element.  A templated implementation might need to
125   // be declared by subclasses.
126   void print(outputStream* out, T& e);
127 
print(outputStream * out,EventRecord<T> & e)128   void print(outputStream* out, EventRecord<T>& e) {
129     out->print("Event: %.3f ", e.timestamp);
130     if (e.thread != NULL) {
131       out->print("Thread " INTPTR_FORMAT " ", p2i(e.thread));
132     }
133     print(out, e.data);
134   }
135 };
136 
137 // A simple wrapper class for fixed size text messages.
138 template <size_t bufsz>
139 class FormatStringLogMessage : public FormatBuffer<bufsz> {
140 };
141 typedef FormatStringLogMessage<256> StringLogMessage;
142 typedef FormatStringLogMessage<512> ExtendedStringLogMessage;
143 
144 // A simple ring buffer of fixed size text messages.
145 template <size_t bufsz>
146 class FormatStringEventLog : public EventLogBase< FormatStringLogMessage<bufsz> > {
147  public:
FormatStringEventLog(const char * name,int count=LogEventsBufferEntries)148   FormatStringEventLog(const char* name, int count = LogEventsBufferEntries) : EventLogBase< FormatStringLogMessage<bufsz> >(name, count) {}
149 
logv(Thread * thread,const char * format,va_list ap)150   void logv(Thread* thread, const char* format, va_list ap) ATTRIBUTE_PRINTF(3, 0) {
151     if (!this->should_log()) return;
152 
153     double timestamp = this->fetch_timestamp();
154     MutexLockerEx ml(&this->_mutex, Mutex::_no_safepoint_check_flag);
155     int index = this->compute_log_index();
156     this->_records[index].thread = thread;
157     this->_records[index].timestamp = timestamp;
158     this->_records[index].data.printv(format, ap);
159   }
160 
log(Thread * thread,const char * format,...)161   void log(Thread* thread, const char* format, ...) ATTRIBUTE_PRINTF(3, 4) {
162     va_list ap;
163     va_start(ap, format);
164     this->logv(thread, format, ap);
165     va_end(ap);
166   }
167 
168 };
169 typedef FormatStringEventLog<256> StringEventLog;
170 typedef FormatStringEventLog<512> ExtendedStringEventLog;
171 
172 
173 
174 class Events : AllStatic {
175   friend class EventLog;
176 
177  private:
178   static EventLog* _logs;
179 
180   // A log for generic messages that aren't well categorized.
181   static StringEventLog* _messages;
182 
183   // A log for internal exception related messages, like internal
184   // throws and implicit exceptions.
185   static ExtendedStringEventLog* _exceptions;
186 
187   // Deoptization related messages
188   static StringEventLog* _deopt_messages;
189 
190   // Redefinition related messages
191   static StringEventLog* _redefinitions;
192 
193  public:
194   static void print_all(outputStream* out);
195 
196   // Dump all events to the tty
197   static void print();
198 
199   // Logs a generic message with timestamp and format as printf.
200   static void log(Thread* thread, const char* format, ...) ATTRIBUTE_PRINTF(2, 3);
201 
202   // Log exception related message
203   static void log_exception(Thread* thread, const char* format, ...) ATTRIBUTE_PRINTF(2, 3);
204 
205   static void log_redefinition(Thread* thread, const char* format, ...) ATTRIBUTE_PRINTF(2, 3);
206 
207   static void log_deopt_message(Thread* thread, const char* format, ...) ATTRIBUTE_PRINTF(2, 3);
208 
209   // Register default loggers
210   static void init();
211 };
212 
log(Thread * thread,const char * format,...)213 inline void Events::log(Thread* thread, const char* format, ...) {
214   if (LogEvents && _messages != NULL) {
215     va_list ap;
216     va_start(ap, format);
217     _messages->logv(thread, format, ap);
218     va_end(ap);
219   }
220 }
221 
log_exception(Thread * thread,const char * format,...)222 inline void Events::log_exception(Thread* thread, const char* format, ...) {
223   if (LogEvents && _exceptions != NULL) {
224     va_list ap;
225     va_start(ap, format);
226     _exceptions->logv(thread, format, ap);
227     va_end(ap);
228   }
229 }
230 
log_redefinition(Thread * thread,const char * format,...)231 inline void Events::log_redefinition(Thread* thread, const char* format, ...) {
232   if (LogEvents && _redefinitions != NULL) {
233     va_list ap;
234     va_start(ap, format);
235     _redefinitions->logv(thread, format, ap);
236     va_end(ap);
237   }
238 }
239 
log_deopt_message(Thread * thread,const char * format,...)240 inline void Events::log_deopt_message(Thread* thread, const char* format, ...) {
241   if (LogEvents && _deopt_messages != NULL) {
242     va_list ap;
243     va_start(ap, format);
244     _deopt_messages->logv(thread, format, ap);
245     va_end(ap);
246   }
247 }
248 
249 
250 template <class T>
print_log_on(outputStream * out)251 inline void EventLogBase<T>::print_log_on(outputStream* out) {
252   if (Thread::current_or_null() == NULL) {
253     // Not yet attached? Don't try to use locking
254     print_log_impl(out);
255   } else {
256     MutexLockerEx ml(&_mutex, Mutex::_no_safepoint_check_flag);
257     print_log_impl(out);
258   }
259 }
260 
261 // Dump the ring buffer entries that current have entries.
262 template <class T>
print_log_impl(outputStream * out)263 inline void EventLogBase<T>::print_log_impl(outputStream* out) {
264   out->print_cr("%s (%d events):", _name, _count);
265   if (_count == 0) {
266     out->print_cr("No events");
267     out->cr();
268     return;
269   }
270 
271   if (_count < _length) {
272     for (int i = 0; i < _count; i++) {
273       print(out, _records[i]);
274     }
275   } else {
276     for (int i = _index; i < _length; i++) {
277       print(out, _records[i]);
278     }
279     for (int i = 0; i < _index; i++) {
280       print(out, _records[i]);
281     }
282   }
283   out->cr();
284 }
285 
286 // Implement a printing routine for the StringLogMessage
287 template <>
print(outputStream * out,StringLogMessage & lm)288 inline void EventLogBase<StringLogMessage>::print(outputStream* out, StringLogMessage& lm) {
289   out->print_raw(lm);
290   out->cr();
291 }
292 
293 // Implement a printing routine for the ExtendedStringLogMessage
294 template <>
print(outputStream * out,ExtendedStringLogMessage & lm)295 inline void EventLogBase<ExtendedStringLogMessage>::print(outputStream* out, ExtendedStringLogMessage& lm) {
296   out->print_raw(lm);
297   out->cr();
298 }
299 
300 // Place markers for the beginning and end up of a set of events.
301 // These end up in the default log.
302 class EventMark : public StackObj {
303   StringLogMessage _buffer;
304 
305  public:
306   // log a begin event, format as printf
307   EventMark(const char* format, ...) ATTRIBUTE_PRINTF(2, 3);
308   // log an end event
309   ~EventMark();
310 };
311 
312 #endif // SHARE_VM_UTILITIES_EVENTS_HPP
313