Skip to content

Commit

Permalink
Update verbose log write API calls to use new newline convention
Browse files Browse the repository at this point in the history 
We perform the following changes:

- Update `write` calls to `writeLine` calls where possible
- Update newline convention to print the new line at the end
- Use the tag when printing where possible
- Add lock acquire and release where it is missed

Signed-off-by: Filip Jeremic <[email protected]>
  • Loading branch information
@fjeremic
fjeremic committed Apr 29, 2020
1 parent de6436b commit 813431b
Show file tree
Hide file tree
Showing 7 changed files with 97 additions and 76 deletions.
9 changes: 4 additions & 5 deletions compiler/control/CompileMethod.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -301,8 +301,7 @@ compileMethodFromDetails(
{
if (TR::Options::getCmdLineOptions()->getVerboseOption(TR_VerboseCompileExclude))
{
TR_VerboseLog::write("<JIT: %s cannot be translated>\n",
compilee.signature(&trMemory));
TR_VerboseLog::writeLine(TR_Vlog_INFO, "%s cannot be translated", compilee.signature(&trMemory));
}
return 0;
}
Expand All @@ -313,8 +312,7 @@ compileMethodFromDetails(
// so that we don't have to deal with OOM ugliness below
if (TR::Options::getCmdLineOptions()->getVerboseOption(TR_VerboseCompileExclude))
{
TR_VerboseLog::write("<JIT: %s out-of-memory allocating optimization plan>\n",
compilee.signature(&trMemory));
TR_VerboseLog::writeLine(TR_Vlog_INFO, "%s out-of-memory allocating optimization plan", compilee.signature(&trMemory));
}
return 0;
}
Expand Down Expand Up @@ -386,7 +384,7 @@ compileMethodFromDetails(
{
const char *signature = compilee.signature(&trMemory);
TR_VerboseLog::vlogAcquire();
TR_VerboseLog::writeLine(TR_Vlog_COMP,"(%s) %s @ " POINTER_PRINTF_FORMAT "-" POINTER_PRINTF_FORMAT,
TR_VerboseLog::write(TR_Vlog_COMP, "(%s) %s @ " POINTER_PRINTF_FORMAT "-" POINTER_PRINTF_FORMAT,
compiler.getHotnessName(compiler.getMethodHotness()),
signature,
startPC,
Expand All @@ -401,6 +399,7 @@ compileMethodFromDetails(
);
}

TR_VerboseLog::writeLine("");
TR_VerboseLog::vlogRelease();
trfflush(jitConfig->options.vLogFile);
}
Expand Down
66 changes: 31 additions & 35 deletions compiler/control/OMROptions.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1556,7 +1556,7 @@ OMR::Options::setRegex(char *option, void *base, TR::OptionTable *entry)
TR::SimpleRegex * regex = TR::SimpleRegex::create(option);
*((TR::SimpleRegex**)((char*)base+entry->parm1)) = regex;
if (!regex)
TR_VerboseLog::write("<JIT: Bad regular expression at --> '%s'>\n", option);
TR_VerboseLog::writeLine("Bad regular expression at --> '%s'", option);
return option;
}

Expand All @@ -1567,7 +1567,7 @@ OMR::Options::setStaticRegex(char *option, void *base, TR::OptionTable *entry)
TR::SimpleRegex * regex = TR::SimpleRegex::create(option);
*((TR::SimpleRegex**)entry->parm1) = regex;
if (!regex)
TR_VerboseLog::write("<JIT: Bad regular expression at --> '%s'>\n", option);
TR_VerboseLog::writeLine("Bad regular expression at --> '%s'", option);
return option;
}

Expand Down Expand Up @@ -2247,19 +2247,19 @@ OMR::Options::jitLatePostProcess(TR::OptionSet *optionSet, void * jitConfig)
if (self()->getOption(TR_MimicInterpreterFrameShape))
{
if (self()->getFixedOptLevel() != -1 && self()->getFixedOptLevel() != noOpt)
TR_VerboseLog::write("<JIT: FullSpeedDebug: ignoring user specified optLevel>\n");
TR_VerboseLog::writeLine(TR_Vlog_FSD, "Ignoring user specified optLevel");
if (_countString)
{
//if quickstart is enabled, then message saying it is incompatable with fsdb
if (self()->isVerboseFileSet())
{
if (TR::Options::isQuickstartDetected())
{
TR_VerboseLog::write("<JIT: FullSpeedDebug: ignoring -Xquickstart option>\n");
TR_VerboseLog::writeLine(TR_Vlog_FSD, "Ignoring -Xquickstart option");
}
else
{
TR_VerboseLog::write("<JIT: FullSpeedDebug: ignoring countString>\n");
TR_VerboseLog::writeLine(TR_Vlog_FSD, "Ignoring countString");
}
}
}
Expand Down Expand Up @@ -2317,11 +2317,7 @@ OMR::Options::jitLatePostProcess(TR::OptionSet *optionSet, void * jitConfig)
}
else if (self()->requiresLogFile())
{
if (this == TR::Options::getAOTCmdLineOptions())
TR_VerboseLog::write("<AOT");
else
TR_VerboseLog::write("<JIT");
TR_VerboseLog::write(": trace options require a log file to be specified: log=<filename>)>\n");
TR_VerboseLog::writeLine(TR_Vlog_INFO, "Trace options require a log file to be specified: log=<filename>");
return false;
}

Expand All @@ -2334,7 +2330,7 @@ OMR::Options::jitLatePostProcess(TR::OptionSet *optionSet, void * jitConfig)
fej9->compileMethods(optionSet, jitConfig);
if (self()->getOption(TR_WaitBit))
{
TR_VerboseLog::write("Will call waitOnCompiler\n");
TR_VerboseLog::writeLine("Will call waitOnCompiler");
fej9->waitOnCompiler(jitConfig);
}
}
Expand Down Expand Up @@ -2709,7 +2705,7 @@ OMR::Options::jitPreProcess()
if (_aggressivenessLevel != -1) // -1 means not set
{
if (OMR::Options::isAnyVerboseOptionSet())
TR_VerboseLog::write("\n<JIT: _aggressivenessLevel=%d; must be between 0 and 5; Option ignored\n", _aggressivenessLevel);
TR_VerboseLog::writeLine(TR_Vlog_INFO, "_aggressivenessLevel=%d; must be between 0 and 5; Option ignored", _aggressivenessLevel);
_aggressivenessLevel = -1;
}
}
Expand Down Expand Up @@ -3105,10 +3101,10 @@ OMR::Options::validateOptionsTables(void *feBase, TR_FrontEnd *fe)
}
if (_numJitEntries > 0 && stricmp_ignore_locale((opt-1)->name, opt->name) >= 0)
{
TR_VerboseLog::writeLine(TR_Vlog_FAILURE,"JIT option table entries out of order: ");
TR_VerboseLog::write(TR_Vlog_FAILURE, "JIT option table entries out of order: ");
TR_VerboseLog::write((opt-1)->name);
TR_VerboseLog::write(", ");
TR_VerboseLog::write(opt->name);
TR_VerboseLog::writeLine(opt->name);
return false;
}
#endif
Expand Down Expand Up @@ -3266,7 +3262,7 @@ OMR::Options::processOptionSet(
methodRegex = TR::SimpleRegex::create(endOpt);
if (!methodRegex)
{
TR_VerboseLog::write("<JIT: Bad regular expression at --> '%s'>\n", endOpt);
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Bad regular expression at --> '%s'", endOpt);
return options;
}

Expand All @@ -3277,7 +3273,7 @@ OMR::Options::processOptionSet(
optLevelRegex = TR::SimpleRegex::create(endOpt);
if (!optLevelRegex)
{
TR_VerboseLog::write("<JIT: Bad regular expression at --> '%s'>\n", endOpt);
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Bad regular expression at --> '%s'", endOpt);
return options;
}
}
Expand Down Expand Up @@ -3419,15 +3415,15 @@ OMR::Options::processOptionSet(

if (!endOpt)
{
TR_VerboseLog::write("<JIT: Unable to allocate option string>\n");
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Unable to allocate option string");
return options;
}

char *feEndOpt = TR::Options::processOption(options, TR::Options::_feOptions, _feBase, _numVmEntries, optionSet);

if (!feEndOpt)
{
TR_VerboseLog::write("<JIT: Unable to allocate option string>\n");
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Unable to allocate option string");
return options;
}

Expand All @@ -3437,7 +3433,7 @@ OMR::Options::processOptionSet(
//
if (feEndOpt != options && optionSet)
{
TR_VerboseLog::write("<JIT: Option not allowed in option subset>\n");
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Option not allowed in option subset");
return options;
}

Expand Down Expand Up @@ -3553,7 +3549,7 @@ OMR::Options::processOption(
{
if (opt->msgInfo & NOT_IN_SUBSET)
{
TR_VerboseLog::write("<JIT: option not allowed in option subset>\n");
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Option not allowed in option subset");
opt->msgInfo = 0;
return startOption;
}
Expand All @@ -3577,7 +3573,7 @@ OMR::Options::processOption(
processingMethod = TR::Options::negateProcessingMethod(opt->fcn);
if (!processingMethod)
{
TR_VerboseLog::write("<JIT: '!' is not supported for this option>\n");
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "'!' is not supported for this option");
opt->msgInfo = 0;
return startOption;
}
Expand Down Expand Up @@ -3621,7 +3617,7 @@ OMR::Options::jitPostProcess()
}
else if (self()->requiresLogFile())
{
TR_VerboseLog::write("<JIT: the log file option must be specified when a trace options is used: log=<filename>)>\n");
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Log file option must be specified when a trace options is used: log=<filename>");
return false;
}

Expand All @@ -3640,7 +3636,7 @@ OMR::Options::jitPostProcess()
}
else
{
TR_VerboseLog::write("<JIT: WARNING: ignoring optFile option; unable to read opts from '%s'\n", _optFileName);
TR_VerboseLog::writeLine(TR_Vlog_INFO, "Ignoring optFile option; unable to read opts from '%s'", _optFileName);
}
}
}
Expand Down Expand Up @@ -3848,7 +3844,7 @@ OMR::Options::printOptions(char *options, char *envOptions)
optionsType = "AOT";
TR_Debug::dumpOptions(optionsType, options, envOptions, self(), _jitOptions, TR::Options::_feOptions, _feBase, _fe);
if (_aggressivenessLevel > 0)
TR_VerboseLog::write("\naggressivenessLevel=%u\n", _aggressivenessLevel);
TR_VerboseLog::writeLine("aggressivenessLevel=%u", _aggressivenessLevel);
}


Expand Down Expand Up @@ -4252,13 +4248,13 @@ OMR::Options::setCounts()

if (!_countString)
{
TR_VerboseLog::write("<JIT: Count string could not be allocated>\n");
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Count string could not be allocated");
return dummy_string;
}

if (_initialCount == -1 || _initialBCount == -1 || _initialMILCount == -1)
{
TR_VerboseLog::write("<JIT: Bad string count: %s>\n", _countString);
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Bad string count: '%s'", _countString);
return _countString;
}

Expand Down Expand Up @@ -4565,7 +4561,7 @@ OMR::Options::setAddressEnumerationBits(char *option, void *base, TR::OptionTabl

TR::SimpleRegex * regex = _debug ? TR::SimpleRegex::create(option) : 0;
if (!regex)
TR_VerboseLog::write("<JIT: Bad regular expression at --> '%s'>\n", option);
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Bad regular expression at --> '%s'", option);
else
{
if (TR::SimpleRegex::matchIgnoringLocale(regex, "block"))
Expand Down Expand Up @@ -4593,7 +4589,7 @@ OMR::Options::setAddressEnumerationBits(char *option, void *base, TR::OptionTabl
*((int32_t*)((char*)base+entry->parm1)) |= TR_EnumerateStructure;
}
if (*((int32_t*)((char*)base+entry->parm1)) == 0x00000000)
TR_VerboseLog::write("<JIT: Address enumeration option not found. No address enumeration option was set.>");
TR_VerboseLog::writeLine(TR_Vlog_INFO, "Address enumeration option not found. No address enumeration option was set.");
}
}

Expand Down Expand Up @@ -4664,7 +4660,7 @@ OMR::Options::setBitsFromStringSet(char *option, void *base, TR::OptionTable *en

TR::SimpleRegex * regex = _debug ? TR::SimpleRegex::create(option) : 0;
if (!regex)
TR_VerboseLog::write("<JIT: Bad regular expression at --> '%s'>\n", option);
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Bad regular expression at --> '%s'", option);
else
{
for(i=0;_optionStringToBitMapping[i].bitValue != 0;i++)
Expand All @@ -4675,7 +4671,7 @@ OMR::Options::setBitsFromStringSet(char *option, void *base, TR::OptionTable *en
}
}
if (*((int32_t*)((char*)base+entry->parm1)) == 0x00000000)
TR_VerboseLog::write("<JIT: Register assignment tracing options not found. No additional tracing option was set.>");
TR_VerboseLog::writeLine(TR_Vlog_INFO, "Register assignment tracing options not found. No additional tracing option was set.");
}
}

Expand All @@ -4695,7 +4691,7 @@ char *OMR::Options::clearBitsFromStringSet(char *option, void *base, TR::OptionT
{
TR::SimpleRegex * regex = TR::SimpleRegex::create(option);
if (!regex)
TR_VerboseLog::write("<JIT: Bad regular expression at --> '%s'>\n", option);
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Bad regular expression at --> '%s'", option);
else
{
for(i=0;_optionStringToBitMapping[i].bitValue != 0;i++)
Expand All @@ -4706,7 +4702,7 @@ char *OMR::Options::clearBitsFromStringSet(char *option, void *base, TR::OptionT
}
}
if (*((int32_t*)((char*)base+entry->parm1)) == 0x00000000)
TR_VerboseLog::write("<JIT: Register assignment tracing options not found. No additional tracing option was set.>");
TR_VerboseLog::writeLine(TR_Vlog_INFO, "Register assignment tracing options not found. No additional tracing option was set.");
}
}

Expand All @@ -4732,7 +4728,7 @@ OMR::Options::configureOptReporting(char *option, void *base, TR::OptionTable *e
options->setOption(TR_CountOptTransformations);
TR::SimpleRegex * regex = _debug ? TR::SimpleRegex::create(option) : 0;
if (!regex)
TR_VerboseLog::write("<JIT: Bad regular expression --> '%s'>\n", option);
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Bad regular expression --> '%s'", option);
else
options->_verboseOptTransformationsRegex = regex;
break;
Expand Down Expand Up @@ -4837,7 +4833,7 @@ OMR::Options::setVerboseBitsHelper(char *option, VerboseOptionFlagArray *verbose
{
TR::SimpleRegex * regex = TR::SimpleRegex::create(option);
if (!regex)
TR_VerboseLog::write("<JIT: Bad regular expression at --> '%s'>\n", option);
TR_VerboseLog::writeLine(TR_Vlog_FAILURE, "Bad regular expression at --> '%s'", option);
else
{
bool foundMatch = false;
Expand All @@ -4853,7 +4849,7 @@ OMR::Options::setVerboseBitsHelper(char *option, VerboseOptionFlagArray *verbose
}

if (!foundMatch)
TR_VerboseLog::write("<JIT: Verbose option not found. No verbose option was set.>");
TR_VerboseLog::writeLine(TR_Vlog_INFO, "Verbose option not found. No verbose option was set.");
}
}
return option;
Expand Down
4 changes: 2 additions & 2 deletions compiler/env/CompileTimeProfiler.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -99,14 +99,14 @@ class CompileTimeProfiler
if (TR::Options::getVerboseOption(TR_VerbosePerformance))
{
TR_VerboseLog::vlogAcquire();
TR_VerboseLog::write("\nProfiling %s compile time with:", comp->signature());
TR_VerboseLog::write("Profiling %s compile time with:", comp->signature());
char **iter = options;
while (*iter)
{
TR_VerboseLog::write(" %s", *iter);
iter++;
}
TR_VerboseLog::write("\n");
TR_VerboseLog::writeLine("");
TR_VerboseLog::vlogRelease();
}

Expand Down
27 changes: 24 additions & 3 deletions compiler/env/VerboseLog.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -63,6 +63,7 @@ const char * TR_VerboseLog::_vlogTable[] =
"#PROFILING: ",
"#JITServer: ",
"#AOTCOMPRESSION: ",
"#FSD: ",
};

void TR_VerboseLog::writeLine(TR_VlogTag tag, const char *format, ...)
Expand All @@ -72,7 +73,16 @@ void TR_VerboseLog::writeLine(TR_VlogTag tag, const char *format, ...)
va_start(args, format);
writeTimeStamp();
write(_vlogTable[tag]);
vwrite(format,args);
vwrite(format, args);
write("\n");
va_end(args);
}

void TR_VerboseLog::writeLine(const char *format, ...)
{
va_list args;
va_start(args, format);
vwrite(format, args);
write("\n");
va_end(args);
}
Expand All @@ -85,7 +95,7 @@ void TR_VerboseLog::writeLineLocked(TR_VlogTag tag, const char *format, ...)
va_start(args, format);
writeTimeStamp();
write(_vlogTable[tag]);
vwrite(format,args);
vwrite(format, args);
write("\n");
va_end(args);
vlogRelease();
Expand All @@ -95,7 +105,18 @@ void TR_VerboseLog::write(const char *format, ...)
{
va_list args;
va_start(args, format);
vwrite(format,args);
vwrite(format, args);
va_end(args);
}

void TR_VerboseLog::write(TR_VlogTag tag, const char *format, ...)
{
TR_ASSERT_FATAL(tag != TR_Vlog_null, "TR_Vlog_null is not a valid Vlog tag");
va_list args;
va_start(args, format);
writeTimeStamp();
write(_vlogTable[tag]);
vwrite(format, args);
va_end(args);
}

Expand Down
3 changes: 3 additions & 0 deletions compiler/env/VerboseLog.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -71,6 +71,7 @@ enum TR_VlogTag
TR_Vlog_PROFILING,
TR_Vlog_JITServer,
TR_Vlog_AOTCOMPRESSION,
TR_Vlog_FSD,
TR_Vlog_numTags
};

Expand All @@ -84,7 +85,9 @@ class TR_VerboseLog
//writeLine and write provide multi line write capabilities, and are to be used with vlogAcquire() and vlogRelease(),
//this ensures nice formatted verbose logs
static void write(const char *format, ...);
static void write(TR_VlogTag tag, const char *format, ...);
static void writeLine(TR_VlogTag tag, const char *format, ...);
static void writeLine(const char *format, ...);
//writeLineLocked is a single line print function, it provides the locks for you
static void writeLineLocked(TR_VlogTag tag, const char *format, ...);
static void vlogAcquire(); //defined in each front end
Expand Down
Loading

0 comments on commit 813431b

Please sign in to comment.