8142952: Unified Logging framework does not allow multiple -Xlog: arguments

Reviewed-by: brutisso, sla
This commit is contained in:
Marcus Larsson 2015-11-27 12:37:38 +01:00
parent eb2e04e757
commit f6b238ccda
14 changed files with 246 additions and 42 deletions

View file

@ -33,6 +33,7 @@
#include "logging/logTagSet.hpp" #include "logging/logTagSet.hpp"
#include "memory/allocation.inline.hpp" #include "memory/allocation.inline.hpp"
#include "memory/resourceArea.hpp" #include "memory/resourceArea.hpp"
#include "runtime/mutexLocker.hpp"
#include "runtime/os.inline.hpp" #include "runtime/os.inline.hpp"
#include "utilities/globalDefinitions.hpp" #include "utilities/globalDefinitions.hpp"
@ -127,33 +128,72 @@ void LogConfiguration::delete_output(size_t idx) {
void LogConfiguration::configure_output(size_t idx, const LogTagLevelExpression& tag_level_expression, const LogDecorators& decorators) { void LogConfiguration::configure_output(size_t idx, const LogTagLevelExpression& tag_level_expression, const LogDecorators& decorators) {
assert(idx < _n_outputs, "Invalid index, idx = " SIZE_FORMAT " and _n_outputs = " SIZE_FORMAT, idx, _n_outputs); assert(idx < _n_outputs, "Invalid index, idx = " SIZE_FORMAT " and _n_outputs = " SIZE_FORMAT, idx, _n_outputs);
LogOutput* output = _outputs[idx]; LogOutput* output = _outputs[idx];
output->set_decorators(decorators);
output->set_config_string(tag_level_expression.to_string()); // Clear the previous config description
output->clear_config_string();
bool enabled = false; bool enabled = false;
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) { for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
LogLevelType level = tag_level_expression.level_for(*ts); LogLevelType level = tag_level_expression.level_for(*ts);
if (level != LogLevel::Off) {
enabled = true; // Ignore tagsets that do not, and will not log on the output
if (!ts->has_output(output) && (level == LogLevel::NotMentioned || level == LogLevel::Off)) {
continue;
}
// Update decorators before adding/updating output level,
// so that the tagset will have the necessary decorators when requiring them.
if (level != LogLevel::Off) {
ts->update_decorators(decorators);
}
// Set the new level, if it changed
if (level != LogLevel::NotMentioned) {
ts->set_output_level(output, level);
}
if (level != LogLevel::Off) {
// Keep track of whether or not the output is ever used by some tagset
enabled = true;
if (level == LogLevel::NotMentioned) {
// Look up the previously set level for this output on this tagset
level = ts->level_for(output);
}
// Update the config description with this tagset and level
output->add_to_config_string(ts, level);
} }
ts->update_decorators(decorators);
ts->set_output_level(output, level);
} }
// If the output is not used by any tagset it should be removed, unless it is stdout/stderr. // It is now safe to set the new decorators for the actual output
if (!enabled && idx > 1) { output->set_decorators(decorators);
// Update the decorators on all tagsets to get rid of unused decorators
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
ts->update_decorators();
}
if (enabled) {
assert(strlen(output->config_string()) > 0,
"Should always have a config description if the output is enabled.");
} else if (idx > 1) {
// Output is unused and should be removed.
delete_output(idx); delete_output(idx);
} else {
// Output is either stdout or stderr, which means we can't remove it.
// Update the config description to reflect that the output is disabled.
output->set_config_string("all=off");
} }
} }
void LogConfiguration::disable_output(size_t idx) { void LogConfiguration::disable_output(size_t idx) {
LogOutput* out = _outputs[idx]; LogOutput* out = _outputs[idx];
LogDecorators empty_decorators;
empty_decorators.clear();
// Remove the output from all tagsets. // Remove the output from all tagsets.
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) { for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
ts->set_output_level(out, LogLevel::Off); ts->set_output_level(out, LogLevel::Off);
ts->update_decorators(empty_decorators); ts->update_decorators();
} }
// Delete the output unless stdout/stderr // Delete the output unless stdout/stderr
@ -172,6 +212,36 @@ void LogConfiguration::disable_logging() {
} }
} }
void LogConfiguration::configure_stdout(LogLevelType level, bool exact_match, ...) {
assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
"LogConfiguration lock must be held when calling this function");
size_t i;
va_list ap;
LogTagLevelExpression expr;
va_start(ap, exact_match);
for (i = 0; i < LogTag::MaxTags; i++) {
LogTagType tag = static_cast<LogTagType>(va_arg(ap, int));
expr.add_tag(tag);
if (tag == LogTag::__NO_TAG) {
assert(i > 0, "Must specify at least one tag!");
break;
}
}
assert(i < LogTag::MaxTags || static_cast<LogTagType>(va_arg(ap, int)) == LogTag::__NO_TAG,
"Too many tags specified! Can only have up to " SIZE_FORMAT " tags in a tag set.", LogTag::MaxTags);
va_end(ap);
if (!exact_match) {
expr.set_allow_other_tags();
}
expr.set_level(level);
expr.new_combination();
// Apply configuration to stdout (output #0), with the same decorators as before.
configure_output(0, expr, LogOutput::Stdout->decorators());
}
bool LogConfiguration::parse_command_line_arguments(const char* opts) { bool LogConfiguration::parse_command_line_arguments(const char* opts) {
char* copy = os::strdup_check_oom(opts, mtLogging); char* copy = os::strdup_check_oom(opts, mtLogging);

View file

@ -24,6 +24,7 @@
#ifndef SHARE_VM_LOGGING_LOGCONFIGURATION_HPP #ifndef SHARE_VM_LOGGING_LOGCONFIGURATION_HPP
#define SHARE_VM_LOGGING_LOGCONFIGURATION_HPP #define SHARE_VM_LOGGING_LOGCONFIGURATION_HPP
#include "logging/logLevel.hpp"
#include "memory/allocation.hpp" #include "memory/allocation.hpp"
#include "utilities/globalDefinitions.hpp" #include "utilities/globalDefinitions.hpp"
@ -70,6 +71,14 @@ class LogConfiguration : public AllStatic {
// Disable all logging, equivalent to -Xlog:disable. // Disable all logging, equivalent to -Xlog:disable.
static void disable_logging(); static void disable_logging();
// Configures logging on stdout for the given tags and level combination.
// Intended for mappings between -XX: flags and Unified Logging configuration.
// If exact_match is true, only tagsets with precisely the specified tags will be configured
// (exact_match=false is the same as "-Xlog:<tags>*=<level>", and exact_match=true is "-Xlog:<tags>=<level>").
// Tags should be specified using the LOG_TAGS macro, e.g.
// LogConfiguration::configure_stdout(LogLevel::<level>, <true/false>, LOG_TAGS(<tags>));
static void configure_stdout(LogLevelType level, bool exact_match, ...);
// Parse command line configuration. Parameter 'opts' is the string immediately following the -Xlog: argument ("gc" for -Xlog:gc). // Parse command line configuration. Parameter 'opts' is the string immediately following the -Xlog: argument ("gc" for -Xlog:gc).
static bool parse_command_line_arguments(const char* opts = "all"); static bool parse_command_line_arguments(const char* opts = "all");

View file

@ -25,6 +25,8 @@
#include "logging/logDecorators.hpp" #include "logging/logDecorators.hpp"
#include "runtime/os.inline.hpp" #include "runtime/os.inline.hpp"
const LogDecorators LogDecorators::None = LogDecorators(0);
const char* LogDecorators::_name[][2] = { const char* LogDecorators::_name[][2] = {
#define DECORATOR(n, a) {#n, #a}, #define DECORATOR(n, a) {#n, #a},
DECORATOR_LIST DECORATOR_LIST

View file

@ -73,7 +73,12 @@ class LogDecorators VALUE_OBJ_CLASS_SPEC {
return 1 << decorator; return 1 << decorator;
} }
LogDecorators(uint mask) : _decorators(mask) {
}
public: public:
static const LogDecorators None;
LogDecorators() : _decorators(DefaultDecoratorsMask) { LogDecorators() : _decorators(DefaultDecoratorsMask) {
}; };

View file

@ -58,6 +58,7 @@ class LogLevel : public AllStatic {
#undef LOG_LEVEL #undef LOG_LEVEL
Count, Count,
Invalid, Invalid,
NotMentioned,
First = Off + 1, First = Off + 1,
Last = Error, Last = Error,
Default = Warning, Default = Warning,
@ -65,6 +66,7 @@ class LogLevel : public AllStatic {
}; };
static const char *name(LogLevel::type level) { static const char *name(LogLevel::type level) {
assert(level >= 0 && level < LogLevel::Count, "Invalid level (enum value %d).", level);
return _name[level]; return _name[level];
} }

View file

@ -24,7 +24,9 @@
#include "precompiled.hpp" #include "precompiled.hpp"
#include "logging/logFileStreamOutput.hpp" #include "logging/logFileStreamOutput.hpp"
#include "logging/logOutput.hpp" #include "logging/logOutput.hpp"
#include "logging/logTagSet.hpp"
#include "memory/allocation.inline.hpp" #include "memory/allocation.inline.hpp"
#include "runtime/mutexLocker.hpp"
#include "runtime/os.inline.hpp" #include "runtime/os.inline.hpp"
LogOutput* const LogOutput::Stdout = &LogStdoutOutput::_instance; LogOutput* const LogOutput::Stdout = &LogStdoutOutput::_instance;
@ -34,7 +36,54 @@ LogOutput::~LogOutput() {
os::free(_config_string); os::free(_config_string);
} }
void LogOutput::set_config_string(const char* string) { void LogOutput::clear_config_string() {
assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
"Must hold configuration lock to modify config string");
os::free(_config_string); os::free(_config_string);
_config_string = os::strdup_check_oom(string, mtLogging); _config_string_buffer_size = InitialConfigBufferSize;
_config_string = NEW_C_HEAP_ARRAY(char, _config_string_buffer_size, mtLogging);
_config_string[0] = '\0';
}
void LogOutput::set_config_string(const char* string) {
assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
"Must hold configuration lock to modify config string");
os::free(_config_string);
_config_string = os::strdup(string, mtLogging);
_config_string_buffer_size = strlen(_config_string) + 1;
}
void LogOutput::add_to_config_string(const LogTagSet* ts, LogLevelType level) {
assert(LogConfiguration_lock == NULL || LogConfiguration_lock->owned_by_self(),
"Must hold configuration lock to modify config string");
if (_config_string_buffer_size < InitialConfigBufferSize) {
_config_string_buffer_size = InitialConfigBufferSize;
_config_string = REALLOC_C_HEAP_ARRAY(char, _config_string, _config_string_buffer_size, mtLogging);
}
size_t offset = strlen(_config_string);
for (;;) {
int ret = ts->label(_config_string + offset, _config_string_buffer_size - offset, "+");
if (ret == -1) {
// Double the buffer size and retry
_config_string_buffer_size *= 2;
_config_string = REALLOC_C_HEAP_ARRAY(char, _config_string, _config_string_buffer_size, mtLogging);
continue;
}
break;
};
offset = strlen(_config_string);
for (;;) {
int ret = jio_snprintf(_config_string + offset, _config_string_buffer_size - offset, "=%s,", LogLevel::name(level));
if (ret == -1) {
_config_string_buffer_size *= 2;
_config_string = REALLOC_C_HEAP_ARRAY(char, _config_string, _config_string_buffer_size, mtLogging);
continue;
}
break;
}
} }

View file

@ -25,18 +25,24 @@
#define SHARE_VM_LOGGING_LOGOUTPUT_HPP #define SHARE_VM_LOGGING_LOGOUTPUT_HPP
#include "logging/logDecorators.hpp" #include "logging/logDecorators.hpp"
#include "logging/logLevel.hpp"
#include "memory/allocation.hpp" #include "memory/allocation.hpp"
#include "utilities/globalDefinitions.hpp" #include "utilities/globalDefinitions.hpp"
class LogDecorations; class LogDecorations;
class LogTagSet;
// The base class/interface for log outputs. // The base class/interface for log outputs.
// Keeps track of the latest configuration string, // Keeps track of the latest configuration string,
// and its selected decorators. // and its selected decorators.
class LogOutput : public CHeapObj<mtLogging> { class LogOutput : public CHeapObj<mtLogging> {
private:
static const size_t InitialConfigBufferSize = 256;
char* _config_string;
size_t _config_string_buffer_size;
protected: protected:
LogDecorators _decorators; LogDecorators _decorators;
char* _config_string;
public: public:
static LogOutput* const Stdout; static LogOutput* const Stdout;
@ -54,10 +60,16 @@ class LogOutput : public CHeapObj<mtLogging> {
return _config_string; return _config_string;
} }
LogOutput() : _config_string(NULL) { LogOutput() : _config_string(NULL), _config_string_buffer_size(0) {
} }
virtual ~LogOutput(); virtual ~LogOutput();
// Clears any previous config description in preparation of reconfiguration.
void clear_config_string();
// Adds the tagset on the given level to the config description (e.g. "tag1+tag2=level").
void add_to_config_string(const LogTagSet* ts, LogLevelType level);
// Replaces the current config description with the given string.
void set_config_string(const char* string); void set_config_string(const char* string);
virtual const char* name() const = 0; virtual const char* name() const = 0;

View file

@ -59,7 +59,7 @@ void LogOutputList::set_output_level(LogOutput* output, LogLevelType level) {
} }
} }
LogOutputList::LogOutputNode* LogOutputList::find(LogOutput* output) { LogOutputList::LogOutputNode* LogOutputList::find(const LogOutput* output) const {
for (LogOutputNode* node = _level_start[LogLevel::Last]; node != NULL; node = node->_next) { for (LogOutputNode* node = _level_start[LogLevel::Last]; node != NULL; node = node->_next) {
if (output == node->_value) { if (output == node->_value) {
return node; return node;

View file

@ -56,7 +56,7 @@ class LogOutputList VALUE_OBJ_CLASS_SPEC {
LogOutputNode* _level_start[LogLevel::Count]; LogOutputNode* _level_start[LogLevel::Count];
volatile jint _active_readers; volatile jint _active_readers;
LogOutputNode* find(LogOutput* output); LogOutputNode* find(const LogOutput* output) const;
void remove_output(LogOutputNode* node); void remove_output(LogOutputNode* node);
void add_output(LogOutput* output, LogLevelType level); void add_output(LogOutput* output, LogLevelType level);
void update_output_level(LogOutputNode* node, LogLevelType level); void update_output_level(LogOutputNode* node, LogLevelType level);
@ -69,10 +69,18 @@ class LogOutputList VALUE_OBJ_CLASS_SPEC {
} }
// Test if the outputlist has an output for the given level. // Test if the outputlist has an output for the given level.
bool is_level(LogLevelType level) { bool is_level(LogLevelType level) const {
return _level_start[level] != NULL; return _level_start[level] != NULL;
} }
LogLevelType level_for(const LogOutput* output) const {
LogOutputNode* node = this->find(output);
if (node == NULL) {
return LogLevel::Off;
}
return node->_level;
}
// Set (add/update/remove) the output to the specified level. // Set (add/update/remove) the output to the specified level.
void set_output_level(LogOutput* output, LogLevelType level); void set_output_level(LogOutput* output, LogLevelType level);

View file

@ -29,10 +29,6 @@
const char* LogTagLevelExpression::DefaultExpressionString = "all"; const char* LogTagLevelExpression::DefaultExpressionString = "all";
LogTagLevelExpression::~LogTagLevelExpression() {
os::free(_string);
}
void LogTagLevelExpression::clear() { void LogTagLevelExpression::clear() {
_ntags = 0; _ntags = 0;
_ncombinations = 0; _ncombinations = 0;
@ -43,8 +39,6 @@ void LogTagLevelExpression::clear() {
_tags[combination][tag] = LogTag::__NO_TAG; _tags[combination][tag] = LogTag::__NO_TAG;
} }
} }
os::free(_string);
_string = NULL;
} }
bool LogTagLevelExpression::parse(const char* str, outputStream* errstream) { bool LogTagLevelExpression::parse(const char* str, outputStream* errstream) {
@ -131,15 +125,13 @@ bool LogTagLevelExpression::parse(const char* str, outputStream* errstream) {
new_combination(); new_combination();
} }
// Save the (unmodified) string for printing purposes. os::free(copy);
_string = copy;
strcpy(_string, str);
return success; return success;
} }
LogLevelType LogTagLevelExpression::level_for(const LogTagSet& ts) const { LogLevelType LogTagLevelExpression::level_for(const LogTagSet& ts) const {
LogLevelType level = LogLevel::Off; // Return NotMentioned if the given tagset isn't covered by this expression.
LogLevelType level = LogLevel::NotMentioned;
for (size_t combination = 0; combination < _ncombinations; combination++) { for (size_t combination = 0; combination < _ncombinations; combination++) {
bool contains_all = true; bool contains_all = true;
size_t tag_idx; size_t tag_idx;

View file

@ -24,6 +24,7 @@
#ifndef SHARE_VM_LOGGING_LOGTAGLEVELEXPRESSION_HPP #ifndef SHARE_VM_LOGGING_LOGTAGLEVELEXPRESSION_HPP
#define SHARE_VM_LOGGING_LOGTAGLEVELEXPRESSION_HPP #define SHARE_VM_LOGGING_LOGTAGLEVELEXPRESSION_HPP
#include "logging/logConfiguration.hpp"
#include "logging/logLevel.hpp" #include "logging/logLevel.hpp"
#include "logging/logTag.hpp" #include "logging/logTag.hpp"
#include "memory/allocation.hpp" #include "memory/allocation.hpp"
@ -35,6 +36,7 @@ class LogTagSet;
// Class used to temporary encode a 'what'-expression during log configuration. // Class used to temporary encode a 'what'-expression during log configuration.
// Consists of a combination of tags and levels, e.g. "tag1+tag2=level1,tag3*=level2". // Consists of a combination of tags and levels, e.g. "tag1+tag2=level1,tag3*=level2".
class LogTagLevelExpression : public StackObj { class LogTagLevelExpression : public StackObj {
friend void LogConfiguration::configure_stdout(LogLevelType, bool, ...);
private: private:
static const size_t MaxCombinations = 32; static const size_t MaxCombinations = 32;
static const char* DefaultExpressionString; static const char* DefaultExpressionString;
@ -43,7 +45,6 @@ class LogTagLevelExpression : public StackObj {
LogTagType _tags[MaxCombinations][LogTag::MaxTags]; LogTagType _tags[MaxCombinations][LogTag::MaxTags];
LogLevelType _level[MaxCombinations]; LogLevelType _level[MaxCombinations];
bool _allow_other_tags[MaxCombinations]; bool _allow_other_tags[MaxCombinations];
char* _string;
void new_combination() { void new_combination() {
_ncombinations++; _ncombinations++;
@ -66,14 +67,9 @@ class LogTagLevelExpression : public StackObj {
void clear(); void clear();
public: public:
LogTagLevelExpression() : _ntags(0), _ncombinations(0), _string(NULL) { LogTagLevelExpression() : _ntags(0), _ncombinations(0) {
} }
const char* to_string() const {
return _string;
}
~LogTagLevelExpression();
bool parse(const char* str, outputStream* errstream = NULL); bool parse(const char* str, outputStream* errstream = NULL);
LogLevelType level_for(const LogTagSet& ts) const; LogLevelType level_for(const LogTagSet& ts) const;
}; };

View file

@ -49,7 +49,7 @@ LogTagSet::LogTagSet(LogTagType t0, LogTagType t1, LogTagType t2, LogTagType t3,
_output_list.set_output_level(LogOutput::Stderr, LogLevel::Default); _output_list.set_output_level(LogOutput::Stderr, LogLevel::Default);
} }
bool LogTagSet::is_level(LogLevelType level) { bool LogTagSet::is_level(LogLevelType level) const {
return _output_list.is_level(level); return _output_list.is_level(level);
} }
@ -77,11 +77,11 @@ void LogTagSet::log(LogLevelType level, const char* msg) {
} }
} }
int LogTagSet::label(char* buf, size_t len) { int LogTagSet::label(char* buf, size_t len, const char* separator) const {
int tot_written = 0; int tot_written = 0;
for (size_t i = 0; i < _ntags; i++) { for (size_t i = 0; i < _ntags; i++) {
int written = jio_snprintf(buf + tot_written, len - tot_written, "%s%s", int written = jio_snprintf(buf + tot_written, len - tot_written, "%s%s",
(i == 0 ? "" : ","), (i == 0 ? "" : separator),
LogTag::name(_tag[i])); LogTag::name(_tag[i]));
if (written < 0) { if (written < 0) {
return -1; return -1;

View file

@ -77,17 +77,21 @@ class LogTagSet VALUE_OBJ_CLASS_SPEC {
return false; return false;
} }
LogLevelType level_for(const LogOutput* output) const {
return _output_list.level_for(output);
}
void set_output_level(LogOutput* output, LogLevelType level) { void set_output_level(LogOutput* output, LogLevelType level) {
_output_list.set_output_level(output, level); _output_list.set_output_level(output, level);
} }
// Refresh the decorators for this tagset to contain the decorators for all // Refresh the decorators for this tagset to contain the decorators for all
// of its current outputs combined with the given decorators. // of its current outputs combined with the given decorators.
void update_decorators(const LogDecorators& decorator); void update_decorators(const LogDecorators& decorator = LogDecorators::None);
int label(char *buf, size_t len); int label(char *buf, size_t len, const char* separator = ",") const;
bool has_output(const LogOutput* output); bool has_output(const LogOutput* output);
bool is_level(LogLevelType level); bool is_level(LogLevelType level) const;
void log(LogLevelType level, const char* msg); void log(LogLevelType level, const char* msg);
}; };

View file

@ -0,0 +1,55 @@
/*
* Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved.
* 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.
*/
/*
* @test TestMultipleXlogArgs
* @summary Ensure multiple -Xlog arguments aggregate the logging options.
* @library /testlibrary
*/
import jdk.test.lib.ProcessTools;
import jdk.test.lib.OutputAnalyzer;
public class TestMultipleXlogArgs {
public static void main(String[] args) throws Exception {
ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-Xlog:logging=debug",
"-Xlog:logging=trace",
"-Xlog:defaultmethods=trace",
"-Xlog:defaultmethods=off",
"-Xlog:safepoint=info",
"-Xlog:safepoint=info",
"-version");
OutputAnalyzer output = new OutputAnalyzer(pb.start());
// -Xlog:logging=trace means that the log configuration will be printed.
String stdoutConfigLine = "\\[logging *\\] #0: stdout .*";
// Ensure logging=trace has overwritten logging=debug
output.shouldMatch(stdoutConfigLine + "logging=trace").shouldNotMatch(stdoutConfigLine + "logging=debug");
// Make sure safepoint=info is printed exactly once even though we're setting it twice
output.shouldMatch(stdoutConfigLine + "safepoint=info").shouldNotMatch(stdoutConfigLine + "safepoint=info.*safepoint=info");
// Shouldn't see defaultmethods at all, because disabled tags are not listed
output.shouldNotMatch(stdoutConfigLine + "defaultmethods");
output.shouldHaveExitValue(0);
}
}