search

kieker-monitoring / kieker

Kieker's main repository
Apache License 2.0
70 stars 41 forks source link

[KIEKER-1174] Correctly use a logger in Tools -> Verbose #2693

Closed rju closed 4 days ago

rju commented 4 days ago

JIRA Issue: KIEKER-1174 Correctly use a logger in Tools -> Verbose Original Reporter: Jan Waller

see KIEKER-1138 Done

instead of using println etc., we should use a logger and differenciate using the log levels.

rju commented 4 days ago

author nils-christian -- Mon, 5 May 2014 16:09:20 +0200

Updates on this ticket (my thanks go to Jan btw):


- The tools will usually avoid System.out/System.err. Exception: The output is indeed intended as output of the tool (for example for the timestamp converter tool).
- Usually we write INFO level messages into the kieker.log file and WARN level messages to the console (logging.properties)
- Depending on the parameters, the tools can load another configuration file. We provide two more configuration files. The first one writes also all INFO level messages to the console (logging.verbosely.properties) and the second one shows all DEBUG level messages in the console and writes them to the file as well (logging.debug.properties). New properties files can be loaded as followed: LogManager.getLogManager().readConfiguration(...);
- As it is possible that I destroy something while modifying the tools, I created a new branch for this task (tools-logger-KIEK-1174).
- The tools should probably print a hint that additional information can be found in the kieker.log file. Question is: How to print this message?

rju commented 4 days ago

author nils-christian -- Mon, 12 May 2014 09:50:53 +0200

Current (and hopefully final approach):

  = Console = = Log File =
= Usual Logging = INFO ALL
= Verbose Logging = ALL ALL
= Debug Logging = ALL + Stacktrace ALL + Stacktrace

This means that a lot of INFO messages have to be changed to DEBUG messages.

rju commented 4 days ago

author nils-christian -- Mon, 12 May 2014 09:54:41 +0200

As our command line tools should all have a similar behaviour, I decided to use an abstract base for the tools.

André van Hoorn, Jan Waller: Please visit the branch (Changeset bd21d54dff5546c38d3268ac22342d130d719132) and take a look at the modified command line tools. Do they still behave as you would expect? If you want more or less output, please modify the log messages. I would like to merge back as soon as possible (Make sure to execute them from the command line, as the tools won't find the logging configuration files when started from within Eclipse).

rju commented 4 days ago

author Jan Waller -- Tue, 13 May 2014 10:09:24 +0200

Didn't take a look at the log messages. Could you provide a sample output before and after in this ticket?

rju commented 4 days ago

author nils-christian -- Tue, 13 May 2014 12:32:20 +0200

Replying to [jwa|comment:5]:
> * LogFormatter in common.logging?

Done in 694f24091e9b46a7b272b09a1ecaa4e9065ae647.

> * verbosely.properties -> verbose.properties

Done in 694f24091e9b46a7b272b09a1ecaa4e9065ae647.

> * KaxViz -> please don't remove uncommented code without asking! Please readd!

As discussed in person: No comments were removed.

rju commented 4 days ago

author nils-christian -- Tue, 13 May 2014 12:36:21 +0200

Replying to [jwa|comment:5]:
> Could you provide a sample output before and after in this ticket?

Kax-Viz Before:

Missing required option: i
usage: kieker.tools.KaxViz -i <filename> [-svg <filename>]
 --i,--input <filename>
        the analysis project file (.kax) loaded

 --svg <filename>
        name of svg saved on close

Kax-Viz After:

SCHWERWIEGEND (13.05.2014 12:33:08): An error occurred while parsing the command line arguments
usage: kieker.tools.KaxViz [-d] -i <filename> [-svg <filename>] [-v]
 --d,--debug
        prints additional debug information

 --i,--input <filename>
        the analysis project file (.kax) loaded

 --svg <filename>
        name of svg saved on close

 --v,--verbose
        verbosely prints additional information
See 'kieker.log' for details

Trace Analysis Before:

usage: kieker.tools.traceAnalysis.TraceAnalysisTool -i <dir1 ... dirN> -o <dir>
       [-p <prefix>] [-v] [--plot-Deployment-Sequence-Diagrams]
       [--plot-Assembly-Sequence-Diagrams]
       [--plot-Deployment-Component-Dependency-Graph <responseTimes>
       <responseTimeColoring threshold(ms)>]
       [--plot-Assembly-Component-Dependency-Graph <responseTimes>
       <responseTimeColoring threshold(ms)>] [--plot-Container-Dependency-Graph]
       [--plot-Deployment-Operation-Dependency-Graph <responseTimes>
       <responseTimeColoring threshold(ms)>]
       [--plot-Assembly-Operation-Dependency-Graph <responseTimes>
       <responseTimeColoring threshold(ms)>]
       [--plot-Aggregated-Deployment-Call-Tree]
       [--plot-Aggregated-Assembly-Call-Tree] [--plot-Call-Trees]
       [--print-Message-Traces] [--print-Execution-Traces]
       [--print-invalid-Execution-Traces] [--print-System-Model]
       [--print-Deployment-Equivalence-Classes]
       [--print-Assembly-Equivalence-Classes] [--select-traces <id0 ... idn>]
       [--ignore-invalid-traces] [--max-trace-duration <duration in ms>]
       [--ignore-executions-before-date <yyyyMMdd-HHmmss>]
       [--ignore-executions-after-date <yyyyMMdd-HHmmss>] [--short-labels]
       [--include-self-loops] [--traceColoring <color map file>]
       [--addDescriptions <descriptions file>]
 --i,--inputdirs <dir1 ... dirN>
        Log directories to read data from

 --o,--outputdir <dir>
        Directory for the generated file(s)

 --p,--output-filename-prefix <prefix>
        Prefix for output filenames

 --v,--verbose
        Verbosely list used parameters and processed traces

    --plot-Deployment-Sequence-Diagrams
        Generate and store deployment-level sequence diagrams (.pic)

    --plot-Assembly-Sequence-Diagrams
        Generate and store assembly-level sequence diagrams (.pic)

    --plot-Deployment-Component-Dependency-Graph <responseTimes> <responseTimeColoring threshold(ms)>
        Generate and store a deployment-level component dependency graph (.dot)

    --plot-Assembly-Component-Dependency-Graph <responseTimes> <responseTimeColoring threshold(ms)>
        Generate and store an assembly-level component dependency graph (.dot)

    --plot-Container-Dependency-Graph
        Generate and store a container dependency graph (.dot file)

    --plot-Deployment-Operation-Dependency-Graph <responseTimes> <responseTimeColoring threshold(ms)>
        Generate and store a deployment-level operation dependency graph (.dot)

    --plot-Assembly-Operation-Dependency-Graph <responseTimes> <responseTimeColoring threshold(ms)>
        Generate and store an assembly-level operation dependency graph (.dot)

    --plot-Aggregated-Deployment-Call-Tree
        Generate and store an aggregated deployment-level call tree (.dot)

    --plot-Aggregated-Assembly-Call-Tree
        Generate and store an aggregated assembly-level call tree (.dot)

    --plot-Call-Trees
        Generate and store call trees for the selected traces (.dot)

    --print-Message-Traces
        Save message trace representations of valid traces (.txt)

    --print-Execution-Traces
        Save execution trace representations of valid traces (.txt)

    --print-invalid-Execution-Traces
        Save a execution trace representations of invalid trace artifacts (.txt)

    --print-System-Model
        Save a representation of the internal system model (.html)

    --print-Deployment-Equivalence-Classes
        Output an overview about the deployment-level trace equivalence classes

    --print-Assembly-Equivalence-Classes
        Output an overview about the assembly-level trace equivalence classes

    --select-traces <id0 ... idn>
        Consider only the traces identified by the list of trace IDs. Defaults
        to all traces.

    --ignore-invalid-traces
        If selected, the execution aborts on the occurence of an invalid trace.

    --max-trace-duration <duration in ms>
        Threshold (in ms) after which incomplete traces become invalid. Defaults
        to 600,000 (i.e, 10 minutes).

    --ignore-executions-before-date <yyyyMMdd-HHmmss>
        Executions starting before this date (UTC timezone) are ignored.

    --ignore-executions-after-date <yyyyMMdd-HHmmss>
        Executions ending after this date (UTC timezone) are ignored.

    --short-labels
        If selected, abbreviated labels (e.g., package names) are used in the
        visualizations.

    --include-self-loops
        If selected, self-loops are included in the visualizations.

    --traceColoring <color map file>
        Color traces according to the given color map given as a properties file
        (key: trace ID, value: color in hex format, e.g., 0xff0000 for red; use
        trace ID 'default' to specify the default color)

    --addDescriptions <descriptions file>
        Adds descriptions to elements according to the given file as a
        properties file (key: component ID, e.g., 1; value: description)

Error parsing arguments: Missing required options: i, o

An error occured

See 'kieker.log' for details

Trace Analysis After:

SCHWERWIEGEND (13.05.2014 12:36:06): An error occurred while parsing the command line arguments
usage: kieker.tools.traceAnalysis.TraceAnalysisTool -i <dir1 ... dirN> -o
       <dir> [-p <prefix>] [-v] [-d] [--plot-Deployment-Sequence-Diagrams]
       [--plot-Assembly-Sequence-Diagrams]
       [--plot-Deployment-Component-Dependency-Graph <responseTimes>
       <responseTimeColoring threshold(ms)>]
       [--plot-Assembly-Component-Dependency-Graph <responseTimes>
       <responseTimeColoring threshold(ms)>]
       [--plot-Container-Dependency-Graph]
       [--plot-Deployment-Operation-Dependency-Graph <responseTimes>
       <responseTimeColoring threshold(ms)>]
       [--plot-Assembly-Operation-Dependency-Graph <responseTimes>
       <responseTimeColoring threshold(ms)>]
       [--plot-Aggregated-Deployment-Call-Tree]
       [--plot-Aggregated-Assembly-Call-Tree] [--plot-Call-Trees]
       [--print-Message-Traces] [--print-Execution-Traces]
       [--print-invalid-Execution-Traces] [--print-System-Model]
       [--print-Deployment-Equivalence-Classes]
       [--print-Assembly-Equivalence-Classes] [--select-traces <id0 ...
       idn>] [--ignore-invalid-traces] [--max-trace-duration <duration in
       ms>] [--ignore-executions-before-date <yyyyMMdd-HHmmss>]
       [--ignore-executions-after-date <yyyyMMdd-HHmmss>] [--short-labels]
       [--include-self-loops] [--traceColoring <color map file>]
       [--addDescriptions <descriptions file>]
 --i,--inputdirs <dir1 ... dirN>
        Log directories to read data from

 --o,--outputdir <dir>
        Directory for the generated file(s)

 --p,--output-filename-prefix <prefix>
        Prefix for output filenames

 --v,--verbose
        Verbosely list used parameters and processed traces

 --d,--debug
        prints additional debug information

    --plot-Deployment-Sequence-Diagrams
        Generate and store deployment-level sequence diagrams (.pic)

    --plot-Assembly-Sequence-Diagrams
        Generate and store assembly-level sequence diagrams (.pic)

    --plot-Deployment-Component-Dependency-Graph <responseTimes> <responseTimeColoring threshold(ms)>
        Generate and store a deployment-level component dependency graph
        (.dot)

    --plot-Assembly-Component-Dependency-Graph <responseTimes> <responseTimeColoring threshold(ms)>
        Generate and store an assembly-level component dependency graph
        (.dot)

    --plot-Container-Dependency-Graph
        Generate and store a container dependency graph (.dot file)

    --plot-Deployment-Operation-Dependency-Graph <responseTimes> <responseTimeColoring threshold(ms)>
        Generate and store a deployment-level operation dependency graph
        (.dot)

    --plot-Assembly-Operation-Dependency-Graph <responseTimes> <responseTimeColoring threshold(ms)>
        Generate and store an assembly-level operation dependency graph
        (.dot)

    --plot-Aggregated-Deployment-Call-Tree
        Generate and store an aggregated deployment-level call tree (.dot)

    --plot-Aggregated-Assembly-Call-Tree
        Generate and store an aggregated assembly-level call tree (.dot)

    --plot-Call-Trees
        Generate and store call trees for the selected traces (.dot)

    --print-Message-Traces
        Save message trace representations of valid traces (.txt)

    --print-Execution-Traces
        Save execution trace representations of valid traces (.txt)

    --print-invalid-Execution-Traces
        Save a execution trace representations of invalid trace artifacts
        (.txt)

    --print-System-Model
        Save a representation of the internal system model (.html)

    --print-Deployment-Equivalence-Classes
        Output an overview about the deployment-level trace equivalence
        classes

    --print-Assembly-Equivalence-Classes
        Output an overview about the assembly-level trace equivalence
        classes

    --select-traces <id0 ... idn>
        Consider only the traces identified by the list of trace IDs.
        Defaults to all traces.

    --ignore-invalid-traces
        If selected, the execution aborts on the occurence of an invalid
        trace.

    --max-trace-duration <duration in ms>
        Threshold (in ms) after which incomplete traces become invalid.
        Defaults to 600,000 (i.e, 10 minutes).

    --ignore-executions-before-date <yyyyMMdd-HHmmss>
        Executions starting before this date (UTC timezone) are ignored.

    --ignore-executions-after-date <yyyyMMdd-HHmmss>
        Executions ending after this date (UTC timezone) are ignored.

    --short-labels
        If selected, abbreviated labels (e.g., package names) are used in
        the visualizations.

    --include-self-loops
        If selected, self-loops are included in the visualizations.

    --traceColoring <color map file>
        Color traces according to the given color map given as a
        properties file (key: trace ID, value: color in hex format, e.g.,
        0xff0000 for red; use trace ID 'default' to specify the default
        color)

    --addDescriptions <descriptions file>
        Adds descriptions to elements according to the given file as a
        properties file (key: component ID, e.g., 1; value: description)
See 'kieker.log' for details
rju commented 4 days ago

author nils-christian -- Fri, 6 Jun 2014 15:24:06 +0200

Merged back to the master with 440fdd1f29ac648f5d90bb0cb3f3a572ecde3181 and d9da9bbd9465c550967b368a51ba3c7786534dad.

rju commented 4 days ago

author nils-christian -- Thu, 12 Jun 2014 10:21:14 +0200

The logging is still not working as intended. Although it is now working for the usual tools, the gui shows debug log messages from Swing as well.

rju commented 4 days ago

author nils-christian -- Thu, 12 Jun 2014 10:23:16 +0200

Also: In order to take the stream redirection into account, one has to reinitialize the handlers
- even when using the default logging. Fixed in 6cbf60efede74681e99255771f6eb5ae6de02927.

rju commented 4 days ago

author nils-christian -- Thu, 12 Jun 2014 10:41:52 +0200

For the tools I deactivated each logger except for those within Kieker in 577bbbcd692b3dc8457b73c38d480e10d30ffc30.

However, there is still a weird bug. If one executes the trace analysis tool with the GUI with verbose flag and then deactivates this flag and executes the trace analysis again, a debug log message is printed before the usual log messages:
Registered Repository 'SystemModelRepository-22' (System model repository)
This happens because the repository is created too early and therefore uses the "wrong" logger.

rju commented 4 days ago

author nils-christian -- Thu, 12 Jun 2014 10:46:13 +0200

Should be solved with 26efbc21121f04f7aeeb00b6a3da1cdff3832a22.