# HG changeset patch # User stuefe # Date 1552404339 -3600 # Tue Mar 12 16:25:39 2019 +0100 # Node ID 44e6ba1e6e5363afc9e6b4cd370f9409370ca76f # Parent f1de2a95b393926be03cde295d51a03b339f9acc [mq]: eventlog-with-stringfifo diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/os/posix/os_posix.cpp --- a/src/hotspot/os/posix/os_posix.cpp Fri Mar 08 09:26:00 2019 +0100 +++ b/src/hotspot/os/posix/os_posix.cpp Tue Mar 12 16:25:39 2019 +0100 @@ -1299,7 +1299,11 @@ // so it depends on the context which member to use. For synchronous error signals, // we print si_addr, unless the signal was sent by another process or thread, in // which case we print out pid or tid of the sender. - if (si->si_code == SI_USER || si->si_code == SI_QUEUE) { + if (si->si_code == SI_USER || si->si_code == SI_QUEUE +#ifdef SI_TKILL + || si->si_code == SI_TKILL +#endif + ) { const pid_t pid = si->si_pid; os->print(", si_pid: %ld", (long) pid); if (IS_VALID_PID(pid)) { diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/compiler/compileBroker.cpp --- a/src/hotspot/share/compiler/compileBroker.cpp Fri Mar 08 09:26:00 2019 +0100 +++ b/src/hotspot/share/compiler/compileBroker.cpp Tue Mar 12 16:25:39 2019 +0100 @@ -191,41 +191,38 @@ -class CompilationLog : public StringEventLog { +class CompilationLog : public EventLog { public: - CompilationLog() : StringEventLog("Compilation events") { + CompilationLog() : EventLog("Compilation events", -1, 96, 1 * K) { } void log_compile(JavaThread* thread, CompileTask* task) { - StringLogMessage lm; - stringStream sstr = lm.stream(); + ResourceMark rm; + stringStream st; // msg.time_stamp().update_to(tty->time_stamp().ticks()); - task->print(&sstr, NULL, true, false); - log(thread, "%s", (const char*)lm); + task->print(&st, NULL, true, false); + log_raw(thread, st.base()); } void log_nmethod(JavaThread* thread, nmethod* nm) { - log(thread, "nmethod %d%s " INTPTR_FORMAT " code [" INTPTR_FORMAT ", " INTPTR_FORMAT "]", + logf(thread, "nmethod %d%s " INTPTR_FORMAT " code [" INTPTR_FORMAT ", " INTPTR_FORMAT "]", nm->compile_id(), nm->is_osr_method() ? "%" : "", p2i(nm), p2i(nm->code_begin()), p2i(nm->code_end())); } void log_failure(JavaThread* thread, CompileTask* task, const char* reason, const char* retry_message) { - StringLogMessage lm; - lm.print("%4d COMPILE SKIPPED: %s", task->compile_id(), reason); + ResourceMark rm; + stringStream st; + st.print("%4d COMPILE SKIPPED: %s", task->compile_id(), reason); if (retry_message != NULL) { - lm.append(" (%s)", retry_message); + st.print(" (%s)", retry_message); } - lm.print("\n"); - log(thread, "%s", (const char*)lm); + st.cr(); + logf(thread, "%s", st.base()); } void log_metaspace_failure(const char* reason) { - ResourceMark rm; - StringLogMessage lm; - lm.print("%4d COMPILE PROFILING SKIPPED: %s", -1, reason); - lm.print("\n"); - log(JavaThread::current(), "%s", (const char*)lm); + logf(JavaThread::current(), "%4d COMPILE PROFILING SKIPPED: %s\n", -1, reason); } }; diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/gc/shared/collectedHeap.cpp --- a/src/hotspot/share/gc/shared/collectedHeap.cpp Fri Mar 08 09:26:00 2019 +0100 +++ b/src/hotspot/share/gc/shared/collectedHeap.cpp Tue Mar 12 16:25:39 2019 +0100 @@ -53,32 +53,22 @@ size_t CollectedHeap::_filler_array_max_size = 0; -template <> -void EventLogBase::print(outputStream* st, GCMessage& m) { - st->print_cr("GC heap %s", m.is_before ? "before" : "after"); - st->print_raw(m); -} - void GCHeapLog::log_heap(CollectedHeap* heap, bool before) { if (!should_log()) { return; } + ResourceMark rm; + stringStream st(512); - double timestamp = fetch_timestamp(); - MutexLockerEx ml(&_mutex, Mutex::_no_safepoint_check_flag); - int index = compute_log_index(); - _records[index].thread = NULL; // Its the GC thread so it's not that interesting. - _records[index].timestamp = timestamp; - _records[index].data.is_before = before; - stringStream st(_records[index].data.buffer(), _records[index].data.size()); - + st.print_cr("GC heap %s", before ? "before" : "after"); st.print_cr("{Heap %s GC invocations=%u (full %u):", before ? "before" : "after", heap->total_collections(), heap->total_full_collections()); - heap->print_on(&st); st.print_cr("}"); + + log_raw(NULL, st.base()); } VirtualSpaceSummary CollectedHeap::create_heap_space_summary() { diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/gc/shared/collectedHeap.hpp --- a/src/hotspot/share/gc/shared/collectedHeap.hpp Fri Mar 08 09:26:00 2019 +0100 +++ b/src/hotspot/share/gc/shared/collectedHeap.hpp Tue Mar 12 16:25:39 2019 +0100 @@ -68,12 +68,12 @@ class CollectedHeap; -class GCHeapLog : public EventLogBase { +class GCHeapLog : public EventLog { private: void log_heap(CollectedHeap* heap, bool before); public: - GCHeapLog() : EventLogBase("GC Heap History") {} + GCHeapLog() : EventLog("GC Heap History", -1, 380, 1 * K) {} void log_heap_before(CollectedHeap* heap) { log_heap(heap, true); diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/services/diagnosticCommand.cpp --- a/src/hotspot/share/services/diagnosticCommand.cpp Fri Mar 08 09:26:00 2019 +0100 +++ b/src/hotspot/share/services/diagnosticCommand.cpp Tue Mar 12 16:25:39 2019 +0100 @@ -83,6 +83,7 @@ DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl(full_export, true, false)); DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl(full_export, true, false)); DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl(full_export, true, false)); + DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl(full_export, true, false)); DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl(full_export, true, false)); DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl(full_export, true, false)); DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl(full_export, true, false)); @@ -437,6 +438,40 @@ VMError::print_vm_info(_output); } +VMEventsDCmd::VMEventsDCmd(outputStream* output, bool heap) : DCmdWithParser(output, heap), + _oldest_first("oldest-first", "Entries are printed oldest-to-youngest (default: youngest-to-oldest).", "BOOLEAN", false, "false"), + _max("max", "Maximum number of entries to print. If omitted, all entries are printed.", "STRING", false), + _name("name", "Name of log to print. If omitted, all logs are printed.", "STRING", false) +{ + _dcmdparser.add_dcmd_option(&_oldest_first); + _dcmdparser.add_dcmd_option(&_max); + _dcmdparser.add_dcmd_option(&_name); +} + +int VMEventsDCmd::num_arguments() { + ResourceMark rm; + VMEventsDCmd* dcmd = new VMEventsDCmd(NULL, false); + if (dcmd != NULL) { + DCmdMark mark(dcmd); + return dcmd->_dcmdparser.num_arguments(); + } else { + return 0; + } +} + +void VMEventsDCmd::execute(DCmdSource source, TRAPS) { + const char* max_s = _max.value(); + long max = -1; + if (max_s != NULL) { + char* p = NULL; + max = ::strtol(max_s, &p, 10); + if (max <= 0 || p == max_s) { + max = -1; + } + } + Events::print_all(output(), _name.value(), _oldest_first.value(), max); +} + void SystemGCDCmd::execute(DCmdSource source, TRAPS) { Universe::heap()->collect(GCCause::_dcmd_gc_run); } diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/services/diagnosticCommand.hpp --- a/src/hotspot/share/services/diagnosticCommand.hpp Fri Mar 08 09:26:00 2019 +0100 +++ b/src/hotspot/share/services/diagnosticCommand.hpp Tue Mar 12 16:25:39 2019 +0100 @@ -256,6 +256,26 @@ virtual void execute(DCmdSource source, TRAPS); }; +class VMEventsDCmd : public DCmdWithParser { + DCmdArgument _oldest_first; + DCmdArgument _max; + DCmdArgument _name; +public: + VMEventsDCmd(outputStream* output, bool heap); + static const char* name() { return "VM.events"; } + static const char* description() { + return "Print event log(s)."; + } + static const char* impact() { return "Low"; } + static const JavaPermission permission() { + JavaPermission p = {"java.lang.management.ManagementPermission", + "monitor", NULL}; + return p; + } + static int num_arguments(); + virtual void execute(DCmdSource source, TRAPS); +}; + class SystemGCDCmd : public DCmd { public: SystemGCDCmd(outputStream* output, bool heap) : DCmd(output, heap) { } diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/utilities/events.cpp --- a/src/hotspot/share/utilities/events.cpp Fri Mar 08 09:26:00 2019 +0100 +++ b/src/hotspot/share/utilities/events.cpp Tue Mar 12 16:25:39 2019 +0100 @@ -35,42 +35,233 @@ EventLog* Events::_logs = NULL; -StringEventLog* Events::_messages = NULL; +EventLog* Events::_messages = NULL; ExceptionsEventLog* Events::_exceptions = NULL; -StringEventLog* Events::_redefinitions = NULL; +EventLog* Events::_redefinitions = NULL; UnloadingEventLog* Events::_class_unloading = NULL; -StringEventLog* Events::_deopt_messages = NULL; +EventLog* Events::_deopt_messages = NULL; -EventLog::EventLog() { + +// default implementation will print: timestamp, thread, then call ADDINFO->print(), +// then print record text. All without explicit newlines. +void EventLog::print_record(outputStream* out, const EvntLogRecord* rec) const { + print_record_header(out, rec); + print_record_text(out, rec); + out->cr(); +} + +void EventLog::print_record_header(outputStream* out, const EvntLogRecord* rec) const { + out->print("%.3f " , rec->timestamp); + out->fill_to(20); + if (rec->thread != NULL) { + out->print(INTPTR_FORMAT " ", p2i(rec->thread)); + } + out->fill_to(36); +} + +void EventLog::print_record_text(outputStream* out, const EvntLogRecord* rec) const { + if (!_textbuffer.print_token_if_valid(out, rec->text)) { + out->print(""); + } +} + +int EventLog::calc_records_buffer_size(int requested_size) { + int n = requested_size; + if (n == -1) { + n = LogEventsBufferEntries; + } + if (n <= 0) { + n = 1; + } + return n; +} + +EventLog::EventLog(const char* name, int num_entries, int avg_line_len, int max_line_len) + : _mutex(Mutex::event, name, false, Monitor::_safepoint_check_never), + _name(name), + _records(calc_records_buffer_size(num_entries)), + // Size the text buffer large enough to hold num_entries strings of avg length + _textbuffer(avg_line_len * calc_records_buffer_size(num_entries), max_line_len), + _next(NULL) +{ + Events::register_log(this); +} + +void EventLog::fill_in_record_header(EvntLogRecord* rec, Thread* thread, double timestamp) { + rec->timestamp = timestamp; + if (thread == NULL) { + thread = Thread::current_or_null(); + } + rec->thread = thread; +} + +void EventLog::logvf(Thread* thread, const char* format, va_list ap) { + if (!should_log()) { + return; + } + + double timestamp = os::elapsedTime(); + MutexLockerEx ml(&_mutex, Mutex::_no_safepoint_check_flag); + + EvntLogRecord* next_rec = _records.at(_records.position()); + fill_in_record_header(next_rec, thread, timestamp); + + StringFifoBuffer::token_t tok = _textbuffer.add_string_vfprintf(format, ap); + next_rec->text = tok; + + _records.advance_position(); +} + +void EventLog::logf(Thread* thread, const char* format, ...) { + if (!should_log()) { + return; + } + va_list ap; + va_start(ap, format); + this->logvf(thread, format, ap); + va_end(ap); +} + +void EventLog::log_raw(Thread* thread, const char* msg) { + if (!should_log()) { + return; + } + + double timestamp = os::elapsedTime(); + MutexLockerEx ml(&_mutex, Mutex::_no_safepoint_check_flag); + + EvntLogRecord* next_rec = _records.at(_records.position()); + fill_in_record_header(next_rec, thread, timestamp); + + StringFifoBuffer::token_t tok = _textbuffer.add_string(msg); + next_rec->text = tok; + + _records.advance_position(); +} + +bool EventLog::should_log() { + // Don't bother adding new entries when we're crashing. This also + // avoids mutating the ring buffer when printing the log. + return !VMError::fatal_error_in_progress(); +} + +void EventLog::print_log_impl(outputStream* out, bool old_to_young, int max) const { + + out->print_cr("%s (" UINT64_FORMAT " events)", _name, _records.count()); + + if (_records.empty()) { + return; + } + + // 01234567890123456789012345678901234567890123456789012345678901234567890123456789 + out->print_cr("id time thread"); + + if (old_to_young) { + + // Oldest to youngest + int count = 0; + uint64_t record_id = _records.count(); + // Search backward for first entry to print which is the oldest entry + // within the max range - if given - and which has a still valid text. + int pos = _records.youngest(); + int start = pos; + while (pos != -1 && + (max == -1 || count == max) && + _textbuffer.is_token_valid(_records.at(pos)->text)) + { + start = pos; + record_id --; + count ++; + pos = _records.get_prev(pos); + } + + // Print. + for (int pos = start; pos != -1; pos = _records.get_next(pos)) { + const EvntLogRecord* rec = _records.at(pos); + out->print("[" UINT64_FORMAT "] ", record_id); + out->fill_to(10); + record_id ++; + print_record(out, rec); + } + + } else { + + // Youngest to oldest + int count = 0; + uint64_t record_id = _records.count(); + int pos = _records.youngest(); + while (pos != -1 && + (max == -1 || count < max ) && + _textbuffer.is_token_valid(_records.at(pos)->text)) + { + const EvntLogRecord* rec = _records.at(pos); + out->print("[" UINT64_FORMAT "] ", record_id); + out->fill_to(10); + print_record(out, rec); + pos = _records.get_prev(pos); + count++; + record_id --; + } + + } + +#ifdef ASSERT + _textbuffer.print_statistics(out); +#endif // ASSERT +} + +void EventLog::print_log_on(outputStream* out, bool old_to_young, int max) const { + if (Thread::current_or_null() == NULL) { + // Not yet attached? Don't try to use locking + print_log_impl(out, old_to_young, max); + } else { + MutexLockerEx ml(&_mutex, Mutex::_no_safepoint_check_flag); + print_log_impl(out, old_to_young, max); + } +} + +//////////////////////////////////////////////////////////////// +// Events + +void Events::register_log(EventLog* log) { // This normally done during bootstrap when we're only single // threaded but use a ThreadCritical to ensure inclusion in case // some are created slightly late. ThreadCritical tc; - _next = Events::_logs; - Events::_logs = this; + log->set_next(Events::_logs); + _logs = log; } // For each registered event logger, print out the current contents of // the buffer. This is normally called when the JVM is crashing. -void Events::print_all(outputStream* out) { +void Events::print_all(outputStream* out, const char* log_name, bool old_to_young, int max) { EventLog* log = _logs; while (log != NULL) { - log->print_log_on(out); + // If log_name is given, do a prefix check + if (log_name == NULL || + ::strncasecmp(log->name(), log_name, strlen(log_name)) == 0) { + log->print_log_on(out, old_to_young, max); + out->cr(); + } log = log->next(); } } +void Events::print_all(outputStream* out) { + print_all(out, NULL, true, -1); +} + void Events::print() { print_all(tty); } void Events::init() { if (LogEvents) { - _messages = new StringEventLog("Events"); - _exceptions = new ExceptionsEventLog("Internal exceptions"); - _redefinitions = new StringEventLog("Classes redefined"); - _class_unloading = new UnloadingEventLog("Classes unloaded"); - _deopt_messages = new StringEventLog("Deoptimization events"); + _messages = new EventLog("Events", -1, 128, 1 * K); + _exceptions = new ExceptionsEventLog(); + _redefinitions = new EventLog("Classes redefined", -1, 256, 1 * K); + _class_unloading = new UnloadingEventLog(); + _deopt_messages = new EventLog("Deoptimization events", -1, 256, 1 * K); } } @@ -85,9 +276,8 @@ if (LogEvents) { va_list ap; va_start(ap, format); - // Save a copy of begin message and log it. - _buffer.printv(format, ap); - Events::log(NULL, "%s", _buffer.buffer()); + jio_vsnprintf(_buffer, sizeof(_buffer), format, ap); + Events::log_raw(NULL, _buffer); va_end(ap); } } @@ -95,37 +285,38 @@ EventMark::~EventMark() { if (LogEvents) { // Append " done" to the begin message and log it - _buffer.append(" done"); - Events::log(NULL, "%s", _buffer.buffer()); + Events::log(NULL, "%s done", _buffer); } } +/////////////////////////////////////////////////////////////////////////// +// UnloadingEventLog + void UnloadingEventLog::log(Thread* thread, InstanceKlass* ik) { if (!should_log()) return; - double timestamp = fetch_timestamp(); - // Unloading events are single threaded. - int index = compute_log_index(); - _records[index].thread = thread; - _records[index].timestamp = timestamp; - stringStream st = _records[index].data.stream(); + ResourceMark rm; + stringStream st(512); st.print("Unloading class " INTPTR_FORMAT " ", p2i(ik)); ik->name()->print_value_on(&st); + + log_raw(thread, st.base()); } +/////////////////////////////////////////////////////////////////////////// +// ExceptionsEventLog + void ExceptionsEventLog::log(Thread* thread, Handle h_exception, const char* message, const char* file, int line) { if (!should_log()) return; - double timestamp = fetch_timestamp(); - MutexLockerEx ml(&_mutex, Mutex::_no_safepoint_check_flag); - int index = compute_log_index(); - _records[index].thread = thread; - _records[index].timestamp = timestamp; - stringStream st = _records[index].data.stream(); + ResourceMark rm; + stringStream st(512); st.print("Exception <"); h_exception->print_value_on(&st); st.print("%s%s> (" INTPTR_FORMAT ") \n" "thrown [%s, line %d]\nfor thread " INTPTR_FORMAT, message ? ": " : "", message ? message : "", p2i(h_exception()), file, line, p2i(thread)); + + log_raw(thread, st.base()); } diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/utilities/events.hpp --- a/src/hotspot/share/utilities/events.hpp Fri Mar 08 09:26:00 2019 +0100 +++ b/src/hotspot/share/utilities/events.hpp Tue Mar 12 16:25:39 2019 +0100 @@ -29,191 +29,111 @@ #include "runtime/mutexLocker.hpp" #include "runtime/thread.hpp" #include "utilities/formatBuffer.hpp" +#include "utilities/stringFifoBuffer.hpp" +#include "utilities/fixedSizedFifo.hpp" #include "utilities/vmError.hpp" -// Events and EventMark provide interfaces to log events taking place in the vm. -// This facility is extremly useful for post-mortem debugging. The eventlog -// often provides crucial information about events leading up to the crash. -// -// Abstractly the logs can record whatever they way but normally they -// would record at least a timestamp and the current Thread, along -// with whatever data they need in a ring buffer. Commonly fixed -// length text messages are recorded for simplicity but other -// strategies could be used. Several logs are provided by default but -// new instances can be created as needed. +class outputStream; -// The base event log dumping class that is registered for dumping at -// crash time. This is a very generic interface that is mainly here -// for completeness. Normally the templated EventLogBase would be -// subclassed to provide different log types. class EventLog : public CHeapObj { - friend class Events; - private: + struct EvntLogRecord { + double timestamp; + Thread* thread; + StringFifoBuffer::token_t text; + }; + + mutable Mutex _mutex; + const char* _name; + FixedSizedFifo _records; + StringFifoBuffer _textbuffer; + EventLog* _next; + static int calc_records_buffer_size(int requested_size); + + void fill_in_record_header(EvntLogRecord* rec, Thread* thread, double timestamp); + + void print_record(outputStream* out, const EvntLogRecord* rec) const; + void print_record_header(outputStream* out, const EvntLogRecord* rec) const; + void print_record_text(outputStream* out, const EvntLogRecord* rec) const; + + void print_log_impl(outputStream* out, bool old_to_young, int print_max) const; + +protected: + + bool should_log(); + +public: + + // -1 = default record buffer size (LogEventsBufferEntries) + EventLog(const char* name, int num_entries = -1, int avg_line_len = 80, int max_line_len = 1 * K); + + // Print log + // reverse false: oldest to youngest, true: youngest to oldest entry + // max: print only the top n youngest entries (independent from order); -1 for all. + void print_log_on(outputStream* out, bool old_to_young = true, int max = -1) const; + + // Add to log + void logvf(Thread* thread, const char* format, va_list ap) ATTRIBUTE_PRINTF(3, 0); + + void logf(Thread* thread, const char* format, ...) ATTRIBUTE_PRINTF(3, 4); + + void log_raw(Thread* thread, const char* msg); + + // Log chaining + void set_next(EventLog* log) { _next = log; } EventLog* next() const { return _next; } - public: - // Automatically registers the log so that it will be printed during - // crashes. - EventLog(); + const char* name() const { return _name; } - virtual void print_log_on(outputStream* out) = 0; }; - -// A templated subclass of EventLog that provides basic ring buffer -// functionality. Most event loggers should subclass this, possibly -// providing a more featureful log function if the existing copy -// semantics aren't appropriate. The name is used as the label of the -// log when it is dumped during a crash. -template class EventLogBase : public EventLog { - template class EventRecord : public CHeapObj { - public: - double timestamp; - Thread* thread; - X data; - }; - - protected: - Mutex _mutex; - const char* _name; - int _length; - int _index; - int _count; - EventRecord* _records; - - public: - EventLogBase(const char* name, int length = LogEventsBufferEntries): - _mutex(Mutex::event, name, false, Monitor::_safepoint_check_never), - _name(name), - _length(length), - _index(0), - _count(0) { - _records = new EventRecord[length]; - } - - double fetch_timestamp() { - return os::elapsedTime(); - } - - // move the ring buffer to next open slot and return the index of - // the slot to use for the current message. Should only be called - // while mutex is held. - int compute_log_index() { - int index = _index; - if (_count < _length) _count++; - _index++; - if (_index >= _length) _index = 0; - return index; - } - - bool should_log() { - // Don't bother adding new entries when we're crashing. This also - // avoids mutating the ring buffer when printing the log. - return !VMError::fatal_error_in_progress(); - } - - // Print the contents of the log - void print_log_on(outputStream* out); - - private: - void print_log_impl(outputStream* out); - - // Print a single element. A templated implementation might need to - // be declared by subclasses. - void print(outputStream* out, T& e); - - void print(outputStream* out, EventRecord& e) { - out->print("Event: %.3f ", e.timestamp); - if (e.thread != NULL) { - out->print("Thread " INTPTR_FORMAT " ", p2i(e.thread)); - } - print(out, e.data); - } -}; - -// A simple wrapper class for fixed size text messages. -template -class FormatStringLogMessage : public FormatBuffer { - public: - // Wrap this buffer in a stringStream. - stringStream stream() { - return stringStream(this->_buf, this->size()); - } -}; -typedef FormatStringLogMessage<256> StringLogMessage; -typedef FormatStringLogMessage<512> ExtendedStringLogMessage; - -// A simple ring buffer of fixed size text messages. -template -class FormatStringEventLog : public EventLogBase< FormatStringLogMessage > { - public: - FormatStringEventLog(const char* name, int count = LogEventsBufferEntries) : EventLogBase< FormatStringLogMessage >(name, count) {} - - void logv(Thread* thread, const char* format, va_list ap) ATTRIBUTE_PRINTF(3, 0) { - if (!this->should_log()) return; - - double timestamp = this->fetch_timestamp(); - MutexLockerEx ml(&this->_mutex, Mutex::_no_safepoint_check_flag); - int index = this->compute_log_index(); - this->_records[index].thread = thread; - this->_records[index].timestamp = timestamp; - this->_records[index].data.printv(format, ap); - } - - void log(Thread* thread, const char* format, ...) ATTRIBUTE_PRINTF(3, 4) { - va_list ap; - va_start(ap, format); - this->logv(thread, format, ap); - va_end(ap); - } -}; -typedef FormatStringEventLog<256> StringEventLog; -typedef FormatStringEventLog<512> ExtendedStringEventLog; - class InstanceKlass; // Event log for class unloading events to materialize the class name in place in the log stream. -class UnloadingEventLog : public EventLogBase { +class UnloadingEventLog : public EventLog { public: - UnloadingEventLog(const char* name, int count = LogEventsBufferEntries) : EventLogBase(name, count) {} + UnloadingEventLog() : EventLog("Classes unloaded", -1, 128, 1 * K) {} void log(Thread* thread, InstanceKlass* ik); }; // Event log for exceptions -class ExceptionsEventLog : public ExtendedStringEventLog { +class ExceptionsEventLog : public EventLog { public: - ExceptionsEventLog(const char* name, int count = LogEventsBufferEntries) : ExtendedStringEventLog(name, count) {} + ExceptionsEventLog() : EventLog("Internal Exceptions", -1, 256, 1 * K) {} void log(Thread* thread, Handle h_exception, const char* message, const char* file, int line); }; class Events : AllStatic { - friend class EventLog; - private: static EventLog* _logs; // A log for generic messages that aren't well categorized. - static StringEventLog* _messages; + static EventLog* _messages; // A log for internal exception related messages, like internal // throws and implicit exceptions. static ExceptionsEventLog* _exceptions; // Deoptization related messages - static StringEventLog* _deopt_messages; + static EventLog* _deopt_messages; // Redefinition related messages - static StringEventLog* _redefinitions; + static EventLog* _redefinitions; // Class unloading events static UnloadingEventLog* _class_unloading; public: + + static void register_log(EventLog* log); + + static void print_all(outputStream* out, const char* log_name, bool old_to_young, int max); + + // print_all in default order, all logs, all entries static void print_all(outputStream* out); // Dump all events to the tty @@ -221,6 +141,7 @@ // Logs a generic message with timestamp and format as printf. static void log(Thread* thread, const char* format, ...) ATTRIBUTE_PRINTF(2, 3); + static void log_raw(Thread* thread, const char* text); // Log exception related message static void log_exception(Thread* thread, const char* format, ...) ATTRIBUTE_PRINTF(2, 3); @@ -240,16 +161,20 @@ if (LogEvents) { va_list ap; va_start(ap, format); - _messages->logv(thread, format, ap); + _messages->logvf(thread, format, ap); va_end(ap); } } +inline void Events::log_raw(Thread* thread, const char* text) { + _messages->log_raw(thread, text); +} + inline void Events::log_exception(Thread* thread, const char* format, ...) { if (LogEvents) { va_list ap; va_start(ap, format); - _exceptions->logv(thread, format, ap); + _exceptions->logvf(thread, format, ap); va_end(ap); } } @@ -264,7 +189,7 @@ if (LogEvents) { va_list ap; va_start(ap, format); - _redefinitions->logv(thread, format, ap); + _redefinitions->logvf(thread, format, ap); va_end(ap); } } @@ -279,70 +204,21 @@ if (LogEvents) { va_list ap; va_start(ap, format); - _deopt_messages->logv(thread, format, ap); + _deopt_messages->logvf(thread, format, ap); va_end(ap); } } - -template -inline void EventLogBase::print_log_on(outputStream* out) { - if (Thread::current_or_null() == NULL) { - // Not yet attached? Don't try to use locking - print_log_impl(out); - } else { - MutexLockerEx ml(&_mutex, Mutex::_no_safepoint_check_flag); - print_log_impl(out); - } -} - -// Dump the ring buffer entries that current have entries. -template -inline void EventLogBase::print_log_impl(outputStream* out) { - out->print_cr("%s (%d events):", _name, _count); - if (_count == 0) { - out->print_cr("No events"); - out->cr(); - return; - } - - if (_count < _length) { - for (int i = 0; i < _count; i++) { - print(out, _records[i]); - } - } else { - for (int i = _index; i < _length; i++) { - print(out, _records[i]); - } - for (int i = 0; i < _index; i++) { - print(out, _records[i]); - } - } - out->cr(); -} - -// Implement a printing routine for the StringLogMessage -template <> -inline void EventLogBase::print(outputStream* out, StringLogMessage& lm) { - out->print_raw(lm); - out->cr(); -} - -// Implement a printing routine for the ExtendedStringLogMessage -template <> -inline void EventLogBase::print(outputStream* out, ExtendedStringLogMessage& lm) { - out->print_raw(lm); - out->cr(); -} - // Place markers for the beginning and end up of a set of events. // These end up in the default log. class EventMark : public StackObj { - StringLogMessage _buffer; + char _buffer [512]; public: + // log a begin event, format as printf - EventMark(const char* format, ...) ATTRIBUTE_PRINTF(2, 3); + EventMark(const char* text, ...) ATTRIBUTE_PRINTF(2, 3); + // log an end event ~EventMark(); }; diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/utilities/fixedSizedFifo.hpp --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/src/hotspot/share/utilities/fixedSizedFifo.hpp Tue Mar 12 16:25:39 2019 +0100 @@ -0,0 +1,141 @@ +/* + * Copyright (c) 2019, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2019, SAP + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + * + */ + +#ifndef SHARE_UTILITIES_FIXED_SIZED_FIFO_HPP +#define SHARE_UTILITIES_FIXED_SIZED_FIFO_HPP + +#include "memory/allocation.hpp" +#include "utilities/debug.hpp" +#include "utilities/globalDefinitions.hpp" + +template +class FixedSizedFifo { + + const int _size; + int _pos; // next write position + bool _did_wrap; + uint64_t _count; // total number of items added + + T* _values; + +#ifdef ASSERT + bool is_valid_pos(int pos) const { + return pos >= 0 && (_did_wrap ? pos < _size : pos < _pos); + } +#endif + +public: + + // size - number of records + FixedSizedFifo(int size) + : _size(size), _pos(0), _did_wrap(false), _count(0), _values(NULL) + { + _values = (T*) NEW_C_HEAP_ARRAY(T, size, mtInternal); + assert(_values != NULL, "sanity"); + } + + ~FixedSizedFifo() { + FREE_C_HEAP_ARRAY(T, _values); + } + + const T* at(int pos) const { return _values + pos; } + T* at(int pos) { return _values + pos; } + + uint64_t count() const { + return _count; + } + + bool empty() const { + return _count == 0; + } + + int oldest() const { + if (empty()) { + return -1; + } + if (_did_wrap) { + return _pos; + } else { + return 0; + } + } + + int youngest() const { + if (empty()) { + return -1; + } + if (_pos > 0) { + return _pos - 1; + } else { + return _size - 1; + } + } + + int get_prev(int pos) const { + if (empty() || pos == oldest()) { + return -1; + } + if (pos == 0) { + assert(_did_wrap, "sanity"); + return _size - 1; + } + return pos - 1; + } + + int get_next(int pos) const { + if (empty() || pos == youngest()) { + return -1; + } + if (pos == _size - 1) { + return 0; + } + return pos + 1; + } + + // Adding + + // Position of the next write + int position() const { + return _pos; + } + + void advance_position() { + if (_pos == _size - 1) { + _pos = 0; _did_wrap = true; + } else { + _pos ++; + } + _count ++; + } + + void add(T item) { + _values[_pos] = item; + advance_position(); + } + +}; + +#endif // SHARE_UTILITIES_FIXED_SIZED_FIFO_HPP + diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/utilities/stringFifoBuffer.cpp --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/src/hotspot/share/utilities/stringFifoBuffer.cpp Tue Mar 12 16:25:39 2019 +0100 @@ -0,0 +1,218 @@ +/* + * Copyright (c) 2019, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2019, SAP + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + * + */ + +#include "precompiled.hpp" + +#include "jvm.h" +#include "runtime/os.hpp" +#include "utilities/debug.hpp" +#include "utilities/ostream.hpp" +#include "utilities/stringFifoBuffer.hpp" + +#include + +StringFifoBuffer::StringFifoBuffer(size_t size, size_t max_string_length) + : _size(size), + _max_string_length(max_string_length), + _buffer(NULL), _pos(0), _age(0) +#ifdef ASSERT + , _num_added(0), _sum_len(0), _max_len(0) +#endif +{ + assert(max_string_length > 0 && max_string_length < size, "invalid parameters"); + _buffer = (char*) os::malloc(size, mtInternal); + assert(_buffer != NULL, "Out of memory"); +} + +StringFifoBuffer::~StringFifoBuffer() { + os::free(_buffer); +} + +// Add a string to the buffer. Will return a token to the added string +// in tok. Note: string may be truncated either if the line cap was hit. +StringFifoBuffer::token_t StringFifoBuffer::add_string(const char* string) { + + unsigned cpylen = MIN2(_max_string_length, (unsigned)strlen(string)); + + if (space_left_before_wrap() <= cpylen) { // enough space left for string and terminating zero? + _pos = 0; _age ++; // No. Wrap. + } + + token_t tok; + tok.pos = _pos; + tok.age = _age; + + ::memcpy(_buffer + _pos, string, cpylen); + _pos += cpylen; + _buffer[_pos] = '\0'; + _pos ++; + + if (_pos == _size) { + _pos = 0; _age ++; + } + +#ifdef ASSERT + _num_added ++; + _sum_len += cpylen; + if (cpylen > _max_len) { + _max_len = cpylen; + } +#endif + + return tok; + +} + +// Add a string to the buffer. Will return a token to the added string +// in tok. Note: string will be truncated if max_string_length is hit. +StringFifoBuffer::token_t StringFifoBuffer::add_string_printf(const char* fmt, ...) { + StringFifoBuffer::token_t t; + va_list ap; + va_start(ap, fmt); + t = add_string_vfprintf(fmt, ap); + va_end(ap); + return t; +} + +// Add a string to the buffer. Will return a token to the added string +// in tok. Note: string will be truncated if max_string_length is hit. +StringFifoBuffer::token_t StringFifoBuffer::add_string_vfprintf(const char* fmt, va_list ap) { + + // Shortcut for "%s" + if (::strcmp(fmt, "%s") == 0) { + const char* s = va_arg(ap, const char*); + return add_string(s); + } + + unsigned space_left = space_left_before_wrap(); + + // Note: we directly vsnprintf into the buffer to avoid having to allocate temp mem and having + // to copy strings around. + // This is tricky insofar as we do not know exactly how long the rolled out string is going + // to be. However, we have a limit, _max_string_length, after which it would truncate anyway. + // + // So, we can have two kind of truncation here: + // a) hitting the max allowed size of a string. That is fine and by design, we just ignore that. + // b) hitting the end of the buffer. In that case, we will wrap and print again at the start of the buffer. + // + + if (_max_string_length < space_left) { + // case (a). Just print, limited to _max_string_length. + jio_vsnprintf(_buffer + _pos, _max_string_length + 1, fmt, ap); + } else { + // case (b). We are close to the end, and may have to repeat the printing if we truncated + // too early. + + // If is it obvious that we should wrap, just do it now. + if (strlen(fmt) >= space_left) { + _pos = 0; _age ++; // wrap. + } + + // Attempt to print - may truncate, therefore copy the va_list first, since we may need to try a second time. + va_list ap2; + va_copy(ap2, ap); + if (jio_vsnprintf(_buffer + _pos, space_left, fmt, ap) == -1) { + // wrap and retry. + _pos = 0; _age ++; + jio_vsnprintf(_buffer, _max_string_length + 1, fmt, ap2); + } + } + + token_t tok; + tok.pos = _pos; + tok.age = _age; + + size_t len = strlen(_buffer + _pos); + +#ifdef ASSERT + _num_added ++; + _sum_len += len; + if (len > _max_len) { + _max_len = len; + } +#endif + + _pos += len + 1; + + if (_pos == _size) { + _pos = 0; _age ++; + } + + return tok; + +} + +// given a token, check if it is still valid. +bool StringFifoBuffer::is_token_valid(StringFifoBuffer::token_t tok) const { + bool valid = false; + if (tok.age == _age) { // Same gen? Should always be valid. +#ifdef ASSERT + // String shall be wholly contained in the written portion of the buffer. + const char* s = _buffer + tok.pos; + assert(s + strlen(s) < _buffer + _pos, "sanity"); +#endif + valid = true; + } else if (tok.age == (_age - 1)) { // last gen token. Valid if not yet overwritten. + valid = tok.pos >= _pos; + } + return valid; +} + +// given a token, attempt to print it. If the string is still contained in the +// buffer, will print the string and return true. If not, will return false. +bool StringFifoBuffer::print_token_if_valid(outputStream* st, StringFifoBuffer::token_t tok) const { + + assert(tok.pos < _size, "invalid token"); + + if (is_token_valid(tok)) { + st->print_raw(_buffer + tok.pos); + return true; + } + + return false; + +} + +#ifdef ASSERT +void StringFifoBuffer::print_on(outputStream* st) const { + st->print_cr("age: %u pos: %u", _age, _pos); + for (size_t i = 0; i < _size; i ++) { + if (_buffer[i] != 0) { + st->put(_buffer[i]); + } else { + st->print_raw("\\0"); + } + } +} +void StringFifoBuffer::print_statistics(outputStream* st) const { + const uint64_t avg_len = + _num_added > 0 ? _sum_len / _num_added : 0; + st->print_cr("num_added " UINT64_FORMAT ", avg len: " UINT64_FORMAT ", max len: " UINT64_FORMAT ".", + _num_added, avg_len, _max_len); +} +#endif // ASSERT + + + diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/utilities/stringFifoBuffer.hpp --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/src/hotspot/share/utilities/stringFifoBuffer.hpp Tue Mar 12 16:25:39 2019 +0100 @@ -0,0 +1,102 @@ +/* + * Copyright (c) 2019, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2019, SAP + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + * + */ + +#ifndef SHARE_UTILITIES_STRING_FIFO_BUFFER_HPP +#define SHARE_UTILITIES_STRING_FIFO_BUFFER_HPP + +#include "utilities/globalDefinitions.hpp" + +class outputStream; + +class StringFifoBuffer { + friend class StringFifoBufferTest; + +public: + + struct token_t { + unsigned pos; + unsigned age; + }; + +private: + + // Total size of the whole buffer, in bytes. + const unsigned _size; + + // Maximum length of an individual string, excluding terminating zero; + // longer strings are truncated. + const unsigned _max_string_length; + + char* _buffer; + + // Next writing position + unsigned _pos; + + // Number of wrap-arounds + unsigned _age; + +#ifdef ASSERT + uint64_t _num_added; + uint64_t _sum_len; + uint64_t _max_len; +#endif + + unsigned space_left_before_wrap() const { return _size - _pos; } + + void wrap() { _age ++; _pos = 0; } + +public: + +#ifdef ASSERT + void print_on(outputStream* st) const; +#endif + + StringFifoBuffer(size_t size, size_t max_string_len); + ~StringFifoBuffer(); + + // given a token, check if it is still valid. + bool is_token_valid(token_t tok) const; + + // Add a string to the buffer. Will return a token to the added string + // in tok. Note: string will be truncated if max_string_length is hit. + token_t add_string(const char* string); + + // Add a string to the buffer. Will return a token to the added string + // in tok. Note: string will be truncated if max_string_length is hit. + token_t add_string_printf(const char* fmt, ...); + + // Add a string to the buffer. Will return a token to the added string + // in tok. Note: string will be truncated if max_string_length is hit. + token_t add_string_vfprintf(const char* fmt, va_list ap); + + // given a token, attempt to print it. If the string is still contained in the + // buffer, will print the string and return true. If not, will return false. + bool print_token_if_valid(outputStream* st, token_t tok) const; + + DEBUG_ONLY(void print_statistics(outputStream* st) const;) + +}; + +#endif // SHARE_UTILITIES_STRING_FIFO_BUFFER_HPP diff -r f1de2a95b393 -r 44e6ba1e6e53 src/hotspot/share/utilities/vmError.cpp --- a/src/hotspot/share/utilities/vmError.cpp Fri Mar 08 09:26:00 2019 +0100 +++ b/src/hotspot/share/utilities/vmError.cpp Tue Mar 12 16:25:39 2019 +0100 @@ -1693,12 +1693,12 @@ // generate a native synchronous SIGFPE where possible; // if that did not cause a signal (e.g. on ppc), just // raise the signal. - volatile int x = 0; - volatile int y = 1/x; + // volatile int x = 0; + // volatile int y = 1/x; #ifndef _WIN32 // OSX implements raise(sig) incorrectly so we need to // explicitly target the current thread - pthread_kill(pthread_self(), SIGFPE); + pthread_kill(pthread_self(), SIGILL); #endif } // end: crash_with_sigfpe diff -r f1de2a95b393 -r 44e6ba1e6e53 test/hotspot/gtest/utilities/test_fixedSizedFifo.cpp --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/test/hotspot/gtest/utilities/test_fixedSizedFifo.cpp Tue Mar 12 16:25:39 2019 +0100 @@ -0,0 +1,120 @@ +/* + * Copyright (c) 2019, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2019, SAP. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + * + */ + +#include "precompiled.hpp" +#include "utilities/fixedSizedFifo.hpp" +#include "utilities/globalDefinitions.hpp" +#include "unittest.hpp" + + +template +void iterate_over_fifo_and_check_content(const FixedSizedFifo* fifo, int expected_count, T oldest_expected_value, T youngest_expected_value) { + + // Test iteration + // Forward - oldest to youngest + int num_found = 0; + T expected = oldest_expected_value; + for (int pos = fifo->oldest(); pos != -1; pos = fifo->get_next(pos)) { + // tty->print_cr("pos: %d value: %d", pos, (int)(*fifo->at(pos))); + ASSERT_EQ(*fifo->at(pos), expected); + num_found ++; expected ++; + ASSERT_LE(num_found, expected_count); + } + + // Backward + num_found = 0; + expected = youngest_expected_value; + for (int pos = fifo->youngest(); pos != -1; pos = fifo->get_prev(pos)) { + ASSERT_EQ(*fifo->at(pos), expected); + num_found ++; expected --; + ASSERT_LE(num_found, expected_count); + } + +} + +TEST_VM(FixedSizedFifo, basic) { + + FixedSizedFifo fifo(3); + + ASSERT_TRUE(fifo.empty()); + + fifo.add('A'); + + iterate_over_fifo_and_check_content(&fifo, 1, 'A', 'A'); + + fifo.add('B'); + + iterate_over_fifo_and_check_content(&fifo, 2, 'A', 'B'); + + fifo.add('C'); + + iterate_over_fifo_and_check_content(&fifo, 3, 'A', 'C'); + + fifo.add('D'); // wrap + + iterate_over_fifo_and_check_content(&fifo, 3, 'B', 'D'); + + fifo.add('E'); // + + iterate_over_fifo_and_check_content(&fifo, 3, 'C', 'E'); + +} + +TEST_VM(FixedSizedFifo, basic2) { + + const int fifo_sizes[] = { 1, 3, 10, 50, -1 }; + + for (int i = 0; fifo_sizes[i] != -1; i ++) { // test various buffer sizes + + const int fifo_size = fifo_sizes[i]; + + FixedSizedFifo fifo(fifo_size); + + int num_added = 0; + + while (num_added < 3 * fifo_size) { // let buffer wrap two times + + int last_value = 42 + num_added; + fifo.add(last_value); + + num_added ++; + ASSERT_EQ(fifo.count(), (uint64_t)num_added); + + int oldest_expected_value = num_added - fifo_size; + if (oldest_expected_value < 0) { + oldest_expected_value = 0; + } + oldest_expected_value += 42; + const int youngest_expected_value = last_value; + + iterate_over_fifo_and_check_content(&fifo, fifo_size, oldest_expected_value, youngest_expected_value); + + + + + } + } +} + diff -r f1de2a95b393 -r 44e6ba1e6e53 test/hotspot/gtest/utilities/test_stringFifoBuffer.cpp --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/test/hotspot/gtest/utilities/test_stringFifoBuffer.cpp Tue Mar 12 16:25:39 2019 +0100 @@ -0,0 +1,318 @@ +/* + * Copyright (c) 2019, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2019, SAP. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + * + */ + +#include "precompiled.hpp" +#include "memory/allocation.hpp" +#include "runtime/os.hpp" +#include "utilities/debug.hpp" +#include "utilities/ostream.hpp" +#include "utilities/stringFifoBuffer.hpp" +#include "unittest.hpp" + +#define MAX_SINGLE_STRING_LEN 4096 + +// test a token which is expected to be invalid +static void test_invalid_token(const StringFifoBuffer* sfb, StringFifoBuffer::token_t tok) { + char test_buf [1]; + stringStream ss (test_buf, sizeof(test_buf)); + ASSERT_FALSE(sfb->print_token_if_valid(&ss, tok)); +} + +// test a token which is expected to be valid +static void test_valid_token(const StringFifoBuffer* sfb, StringFifoBuffer::token_t tok, const char* expected_string, size_t expected_truncation_at) { + + assert(strlen(expected_string) <= MAX_SINGLE_STRING_LEN, "sanity"); + char expected_truncated [MAX_SINGLE_STRING_LEN + 1]; + strcpy(expected_truncated, expected_string); + if (expected_truncation_at < sizeof(expected_truncated)) { + expected_truncated[expected_truncation_at] = '\0'; + } + + char test_buf [MAX_SINGLE_STRING_LEN + 1]; + memset(test_buf, 0, sizeof(test_buf)); + stringStream ss (test_buf, sizeof(test_buf)); + ASSERT_TRUE(sfb->print_token_if_valid(&ss, tok)); + + ASSERT_TRUE(strcmp(expected_truncated, test_buf) == 0); + +} + +// Returns a random, ra allocated string of len [minlen, maxlen) +static char* get_random_string(size_t minlen, size_t maxlen) { + assert(minlen < maxlen, "sanity"); + const size_t len = (os::random() % (maxlen - minlen)) + minlen; + char* p = NEW_RESOURCE_ARRAY(char, len + 1); + for (size_t i = 0; i < len; i ++) { + p[i] = 'a' + os::random() % 16; + } + p[len] = '\0'; + return p; +} + + + +struct StoredString: public ResourceObj { + + static int next_num() { + static int n = 1; + n ++; + return n; + } + + StoredString* next; + const int num; + char* s; + StringFifoBuffer::token_t tok; + + StoredString() + : next(NULL), num(next_num()), s(NULL) {} + +}; + +class StringFifoBufferTest: public ::testing::Test { + +protected: + + // returns the minimal string capacity the buffer is supposed to have + static int get_minimal_string_capacity(const StringFifoBuffer* buf) { + // n strings incl terminating zero, if not placed optimally may be one less. + return (buf->_size / (buf->_max_string_length + 1)) - 1; + } + + // given a list of stored strings, check: + // - that valid entries yield the correct expected strings + // - that invalid entries yield nothing + // - that invalid entries are followed by valid entries (so, strings get pushed out bottom first) + // - that there is a minimal number of valid entries, corresponding to the minimal string capacity of the buffer. + static void check_stored_string_list(const StringFifoBuffer* buf, const StoredString* list) { + + bool expect_valid = false; + int num_invalid_entries = 0; + int num_valid_entries = 0; + const StoredString* p = list; + while (p != NULL) { + if (buf->is_token_valid(p->tok)) { + expect_valid = true; // from now on all should be valid. + test_valid_token(buf, p->tok, p->s, buf->_max_string_length); + num_valid_entries ++; + } else { + ASSERT_FALSE(expect_valid); + test_invalid_token(buf, p->tok); + num_invalid_entries ++; + } + p = p->next; + } + + // if buffer wrapped, we expect it to hold at least the minimal number of strings + if (buf->_age > 0) { + ASSERT_TRUE(num_valid_entries >= get_minimal_string_capacity(buf)); + } + + } + + void do_test(size_t buffer_len, size_t buffer_max_string_len, + size_t min_string_len, size_t max_string_len) { + + ResourceMark rm; + + StringFifoBuffer buf(buffer_len, buffer_max_string_len); + StoredString* list = NULL; + + // The minimal number of strings this buffer should be able to hold. + const int minimal_string_capacity = get_minimal_string_capacity(&buf); + + const int num_stored_strings = minimal_string_capacity * 2; + + StoredString* last = NULL; + + // test for at least three full buffer wraps + while (buf._age < 3) { + + StoredString* ss = new StoredString; + ss->s = get_random_string(min_string_len, max_string_len); + ss->tok = buf.add_string(ss->s); + + test_valid_token(&buf, ss->tok, ss->s, buffer_max_string_len); + + if (list == NULL) { + list = last = ss; + } else { + last->next = ss; + last = ss; + } + + check_stored_string_list(&buf, list); + + } + + } + + // Test that we don't wrap if there is enough space left even if that is less space than the max string len + static void test_dont_wrap_prematurely() { + StringFifoBuffer buf(10, 9); + // 0123456789 + StringFifoBuffer::token_t t1 = buf.add_string("ABC"); // ABC# + StringFifoBuffer::token_t t2 = buf.add_string("abc"); // ABC#abc# + test_valid_token(&buf, t1, "ABC", 9); + test_valid_token(&buf, t2, "abc", 9); + } + + // Test that we don't wrap if there is enough space left even if that is less space than the max string len + // (using variadic args) + static void test_dont_wrap_prematurely_2() { + StringFifoBuffer buf(10, 9); + // 0123456789 + StringFifoBuffer::token_t t1 = buf.add_string("ABC"); // ABC# + StringFifoBuffer::token_t t2 = buf.add_string_printf("%s", "abc"); // ABC#abc# + test_valid_token(&buf, t1, "ABC", 9); + test_valid_token(&buf, t2, "abc", 9); + } + + static void test_wrap_va_long_format_string() { + StringFifoBuffer buf(10, 9); + StringFifoBuffer::token_t t1 = buf.add_string("ABCDE"); // ABCDE# + // long format string, should wrap + StringFifoBuffer::token_t t2 = buf.add_string_printf("abcdefg%s", ""); // abcdefg# + test_invalid_token(&buf, t1); + test_valid_token(&buf, t2, "abcdefg", 9); + } + + static void test_wrap_va_short_format_string_long_variadic_args() { + StringFifoBuffer buf(10, 9); + StringFifoBuffer::token_t t1 = buf.add_string("ABCDE"); // ABCDE# + // long format string, should wrap + StringFifoBuffer::token_t t2 = buf.add_string_printf("%s", "abcdefg"); // abcdefg# + test_invalid_token(&buf, t1); + test_valid_token(&buf, t2, "abcdefg", 9); + } + + // Test that filling the buffer completely should not result in an invalid pos (pos should wrap) and that nothing should have been overwritten yet. + static void test_use_space_completely_and_wrap() { + StringFifoBuffer buf(10, 9); + // 0123456789 + StringFifoBuffer::token_t t1 = buf.add_string("ABC"); // ABC# + StringFifoBuffer::token_t t2 = buf.add_string("abcde"); // ABC#abcde# + + ASSERT_EQ(buf._pos, (unsigned)0); // should have wrapped + ASSERT_EQ(buf._age, (unsigned)1); // should have wrapped + test_valid_token(&buf, t1, "ABC", 9); // but both strings should still be valid + test_valid_token(&buf, t2, "abcde", 9); + } + + // Same test with variadic args + static void test_use_space_completely_and_wrap_2() { + StringFifoBuffer buf(10, 9); + // 0123456789 + StringFifoBuffer::token_t t1 = buf.add_string("ABC"); // ABC# + StringFifoBuffer::token_t t2 = buf.add_string_printf("%s", "abcde"); // ABC#abcde# + + ASSERT_EQ(buf._pos, (unsigned)0); // should have wrapped + ASSERT_EQ(buf._age, (unsigned)1); // should have wrapped + test_valid_token(&buf, t1, "ABC", 9); // but both strings should still be valid + test_valid_token(&buf, t2, "abcde", 9); + } + +}; + +TEST_VM_F(StringFifoBufferTest, Test_512_64_small_strings) { + do_test(512, 64, 1, 10); +} + +TEST_VM_F(StringFifoBufferTest, Test_1K_128_long_strings_potential_truncation) { + do_test(512, 64, 40, 80); +} + + +TEST_VM_F(StringFifoBufferTest, Test_32K_1K_small_strings) { + do_test(32 * K, 1 * K, 1, 64); +} + +TEST_VM_F(StringFifoBufferTest, Test_32K_1K_medium_strings) { + do_test(32 * K, 1 * K, 30, 256); +} + +TEST_VM_F(StringFifoBufferTest, Test_32K_1K_wide_range) { + do_test(32 * K, 1 * K, 1, 3 * K); +} + +TEST_VM_F(StringFifoBufferTest, Test_32K_1K_long_strings_potential_truncation) { + do_test(32 * K, 1 * K, 1 * K - 128, 1 * K + 128); // testing truncation. +} + +TEST_VM_F(StringFifoBufferTest, Test_absurdly_small) { + do_test(4, 1, 1, 3); +} + +TEST_VM_F(StringFifoBufferTest, Test_variadic_args) { + + StringFifoBuffer buf(60, 20); + + StringFifoBuffer::token_t t1, t2, t3, t4, t5, t6; + // 012345678901234567890123456789012345678901234567890123456789 + t1 = buf.add_string_printf("ABC %s %u", "DEF", 101); // "ABC DEF 101#" + t2 = buf.add_string_printf("%s", "abcdefghijklmnopqrstuvwxyz"); // "ABC DEF 101#abcdefghijklmnopqrst#" + t3 = buf.add_string_printf("The quick brown"); // "ABC DEF 101#abcdefghijklmnopqrst#The quick brown#" + + test_valid_token(&buf, t1, "ABC DEF 101", 20); + test_valid_token(&buf, t2, "abcdefghijklmnopqrstuvwxyz", 20); // should truncate + test_valid_token(&buf, t3, "The quick brown", 20); + + // this should wrap and push out t1 and t2 + t4 = buf.add_string_printf("%s %s %s", "fox", "jumped", "over"); // "fox jumped over#efghijklmnopqrst#The quick brown#" + test_invalid_token(&buf, t1); + test_invalid_token(&buf, t2); + test_valid_token(&buf, t3, "The quick brown", 20); + test_valid_token(&buf, t4, "fox jumped over", 20); + +} + +// Test that we don't wrap if there is enough space left even if that is less space than the max string len +TEST_VM_F(StringFifoBufferTest, Test_dont_wrap_prematurely) { + test_dont_wrap_prematurely(); +} + +// Test that we don't wrap if there is enough space left even if that is less space than the max string len +// (using variadic args) +TEST_VM_F(StringFifoBufferTest, Test_dont_wrap_prematurely_2) { + test_dont_wrap_prematurely_2(); +} + +// Test that filling the buffer completely should not result in an invalid pos (pos should wrap) and that nothing should have been overwritten yet. +TEST_VM_F(StringFifoBufferTest, Test_use_space_completely_and_wrap) { + test_use_space_completely_and_wrap(); +} + +// Same test with variadic args +TEST_VM_F(StringFifoBufferTest, Test_use_space_completely_and_wrap_va) { + test_use_space_completely_and_wrap_2(); +} + +TEST_VM_F(StringFifoBufferTest, Test_wrap_va_long_format_string) { + test_wrap_va_long_format_string(); +} + +TEST_VM_F(StringFifoBufferTest, Test_wrap_va_short_format_string_long_variadic_args) { + test_wrap_va_short_format_string_long_variadic_args(); +}