comparison src/share/vm/utilities/events.cpp @ 4872:aa3d708d67c4

7141200: log some interesting information in ring buffers for crashes Reviewed-by: kvn, jrose, kevinw, brutisso, twisti, jmasa
author never
date Wed, 01 Feb 2012 07:59:01 -0800
parents f08d439fab8c
children 09d00c18e323
comparison
equal deleted inserted replaced
4871:f067b4e0e04b 4872:aa3d708d67c4
1 /* 1 /*
2 * Copyright (c) 1997, 2010, Oracle and/or its affiliates. All rights reserved. 2 * Copyright (c) 1997, 2012, Oracle and/or its affiliates. All rights reserved.
3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. 3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4 * 4 *
5 * This code is free software; you can redistribute it and/or modify it 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 6 * under the terms of the GNU General Public License version 2 only, as
7 * published by the Free Software Foundation. 7 * published by the Free Software Foundation.
24 24
25 #include "precompiled.hpp" 25 #include "precompiled.hpp"
26 #include "memory/allocation.inline.hpp" 26 #include "memory/allocation.inline.hpp"
27 #include "runtime/mutexLocker.hpp" 27 #include "runtime/mutexLocker.hpp"
28 #include "runtime/osThread.hpp" 28 #include "runtime/osThread.hpp"
29 #include "runtime/threadCritical.hpp"
29 #include "runtime/threadLocalStorage.hpp" 30 #include "runtime/threadLocalStorage.hpp"
30 #include "runtime/timer.hpp" 31 #include "runtime/timer.hpp"
31 #include "utilities/events.hpp" 32 #include "utilities/events.hpp"
32 #ifdef TARGET_OS_FAMILY_linux 33 #ifdef TARGET_OS_FAMILY_linux
33 # include "thread_linux.inline.hpp" 34 # include "thread_linux.inline.hpp"
41 #ifdef TARGET_OS_FAMILY_bsd 42 #ifdef TARGET_OS_FAMILY_bsd
42 # include "thread_bsd.inline.hpp" 43 # include "thread_bsd.inline.hpp"
43 #endif 44 #endif
44 45
45 46
46 #ifndef PRODUCT 47 EventLog* Events::_logs = NULL;
48 StringEventLog* Events::_messages = NULL;
49 StringEventLog* Events::_exceptions = NULL;
50 StringEventLog* Events::_deopt_messages = NULL;
47 51
48 //////////////////////////////////////////////////////////////////////////// 52 EventLog::EventLog() {
49 // Event 53 // This normally done during bootstrap when we're only single
54 // threaded but use a ThreadCritical to ensure inclusion in case
55 // some are created slightly late.
56 ThreadCritical tc;
57 _next = Events::_logs;
58 Events::_logs = this;
59 }
50 60
51 typedef u4 EventID; 61 // For each registered event logger, print out the current contents of
52 62 // the buffer. This is normally called when the JVM is crashing.
53 class Event VALUE_OBJ_CLASS_SPEC { 63 void Events::print_all(outputStream* out) {
54 private: 64 EventLog* log = _logs;
55 jlong _time_tick; 65 while (log != NULL) {
56 intx _thread_id; 66 log->print_log_on(out);
57 const char* _format; 67 log = log->next();
58 int _indent;
59 intptr_t _arg_1;
60 intptr_t _arg_2;
61 intptr_t _arg_3;
62
63 // only EventBuffer::add_event() can assign event id
64 friend class EventBuffer;
65 EventID _id;
66
67 public:
68
69 void clear() { _format = NULL; }
70
71 EventID id() const { return _id; }
72
73 void fill(int indent, const char* format, intptr_t arg_1, intptr_t arg_2, intptr_t arg_3) {
74 _format = format;
75 _arg_1 = arg_1;
76 _arg_2 = arg_2;
77 _arg_3 = arg_3;
78
79 _indent = indent;
80
81 _thread_id = os::current_thread_id();
82 _time_tick = os::elapsed_counter();
83 }
84
85 void print_on(outputStream *st) {
86 if (_format == NULL) return;
87 st->print(" %d", _thread_id);
88 st->print(" %3.2g ", (double)_time_tick / os::elapsed_frequency());
89 st->fill_to(20);
90 for (int index = 0; index < _indent; index++) {
91 st->print("| ");
92 }
93 st->print_cr(_format, _arg_1, _arg_2, _arg_3);
94 }
95 };
96
97 ////////////////////////////////////////////////////////////////////////////
98 // EventBuffer
99 //
100 // Simple lock-free event queue. Every event has a unique 32-bit id.
101 // It's fine if two threads add events at the same time, because they
102 // will get different event id, and then write to different buffer location.
103 // However, it is assumed that add_event() is quick enough (or buffer size
104 // is big enough), so when one thread is adding event, there can't be more
105 // than "size" events created by other threads; otherwise we'll end up having
106 // two threads writing to the same location.
107
108 class EventBuffer : AllStatic {
109 private:
110 static Event* buffer;
111 static int size;
112 static jint indent;
113 static volatile EventID _current_event_id;
114
115 static EventID get_next_event_id() {
116 return (EventID)Atomic::add(1, (jint*)&_current_event_id);
117 }
118
119 public:
120 static void inc_indent() { Atomic::inc(&indent); }
121 static void dec_indent() { Atomic::dec(&indent); }
122
123 static bool get_event(EventID id, Event* event) {
124 int index = (int)(id % size);
125 if (buffer[index].id() == id) {
126 memcpy(event, &buffer[index], sizeof(Event));
127 // check id again; if buffer[index] is being updated by another thread,
128 // event->id() will contain different value.
129 return (event->id() == id);
130 } else {
131 // id does not match - id is invalid, or event is overwritten
132 return false;
133 }
134 }
135
136 // add a new event to the queue; if EventBuffer is full, this call will
137 // overwrite the oldest event in the queue
138 static EventID add_event(const char* format,
139 intptr_t arg_1, intptr_t arg_2, intptr_t arg_3) {
140 // assign a unique id
141 EventID id = get_next_event_id();
142
143 // event will be copied to buffer[index]
144 int index = (int)(id % size);
145
146 // first, invalidate id, buffer[index] can't have event with id = index + 2
147 buffer[index]._id = index + 2;
148
149 // make sure everyone has seen that buffer[index] is invalid
150 OrderAccess::fence();
151
152 // ... before updating its value
153 buffer[index].fill(indent, format, arg_1, arg_2, arg_3);
154
155 // finally, set up real event id, now buffer[index] contains valid event
156 OrderAccess::release_store(&(buffer[index]._id), id);
157
158 return id;
159 }
160
161 static void print_last(outputStream *st, int number) {
162 st->print_cr("[Last %d events in the event buffer]", number);
163 st->print_cr("-<thd>-<elapsed sec>-<description>---------------------");
164
165 int count = 0;
166 EventID id = _current_event_id;
167 while (count < number) {
168 Event event;
169 if (get_event(id, &event)) {
170 event.print_on(st);
171 }
172 id--;
173 count++;
174 }
175 }
176
177 static void print_all(outputStream* st) {
178 print_last(st, size);
179 }
180
181 static void init() {
182 // Allocate the event buffer
183 size = EventLogLength;
184 buffer = NEW_C_HEAP_ARRAY(Event, size);
185
186 _current_event_id = 0;
187
188 // Clear the event buffer
189 for (int index = 0; index < size; index++) {
190 buffer[index]._id = index + 1; // index + 1 is invalid id
191 buffer[index].clear();
192 }
193 }
194 };
195
196 Event* EventBuffer::buffer;
197 int EventBuffer::size;
198 volatile EventID EventBuffer::_current_event_id;
199 int EventBuffer::indent;
200
201 ////////////////////////////////////////////////////////////////////////////
202 // Events
203
204 // Events::log() is safe for signal handlers
205 void Events::log(const char* format, ...) {
206 if (LogEvents) {
207 va_list ap;
208 va_start(ap, format);
209 intptr_t arg_1 = va_arg(ap, intptr_t);
210 intptr_t arg_2 = va_arg(ap, intptr_t);
211 intptr_t arg_3 = va_arg(ap, intptr_t);
212 va_end(ap);
213
214 EventBuffer::add_event(format, arg_1, arg_2, arg_3);
215 } 68 }
216 } 69 }
217 70
218 void Events::print_all(outputStream *st) { 71 void Events::init() {
219 EventBuffer::print_all(st); 72 if (LogEvents) {
73 _messages = new StringEventLog("Events");
74 _exceptions = new StringEventLog("Internal exceptions");
75 _deopt_messages = new StringEventLog("Deoptimization events");
76 }
220 } 77 }
221 78
222 void Events::print_last(outputStream *st, int number) { 79 void eventlog_init() {
223 EventBuffer::print_last(st, number); 80 Events::init();
224 } 81 }
225 82
226 /////////////////////////////////////////////////////////////////////////// 83 ///////////////////////////////////////////////////////////////////////////
227 // EventMark 84 // EventMark
228 85
229 EventMark::EventMark(const char* format, ...) { 86 EventMark::EventMark(const char* format, ...) {
230 if (LogEvents) { 87 if (LogEvents) {
231 va_list ap; 88 va_list ap;
232 va_start(ap, format); 89 va_start(ap, format);
233 intptr_t arg_1 = va_arg(ap, intptr_t); 90 // Save a copy of begin message and log it.
234 intptr_t arg_2 = va_arg(ap, intptr_t); 91 _buffer.printv(format, ap);
235 intptr_t arg_3 = va_arg(ap, intptr_t); 92 Events::log(NULL, _buffer);
236 va_end(ap); 93 va_end(ap);
237
238 EventBuffer::add_event(format, arg_1, arg_2, arg_3);
239 EventBuffer::inc_indent();
240 } 94 }
241 } 95 }
242 96
243 EventMark::~EventMark() { 97 EventMark::~EventMark() {
244 if (LogEvents) { 98 if (LogEvents) {
245 EventBuffer::dec_indent(); 99 // Append " done" to the begin message and log it
246 EventBuffer::add_event("done", 0, 0, 0); 100 _buffer.append(" done");
101 Events::log(NULL, _buffer);
247 } 102 }
248 } 103 }
249
250 ///////////////////////////////////////////////////////////////////////////
251
252 void eventlog_init() {
253 EventBuffer::init();
254 }
255
256 int print_all_events(outputStream *st) {
257 EventBuffer::print_all(st);
258 return 1;
259 }
260
261 #else
262
263 void eventlog_init() {}
264 int print_all_events(outputStream *st) { return 0; }
265
266 #endif // PRODUCT