search

kieker-monitoring / kieker

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

[KIEKER-1119] Default AspectJ configuraton produces log that cannot be processed by TraceAnalysisTool #2676

Closed rju closed 6 days ago

rju commented 6 days ago

JIRA Issue: KIEKER-1119 Default AspectJ configuraton produces log that cannot be processed by TraceAnalysisTool Original Reporter: Andre van Hoorn

The fallback AspectJ configuration seems to use provides that produce BeforeOperationObjectEvent and AfterOperationObjectEvent records. However, these are not supported by the TraceAnalysis tool, yet.

Shouldn't we use probes that produce more common records like OperationExecution... or entry/exit records?

This should be a problem for the Quick Start as well, right?

1. Execute example examples/userguide/ch2--bookstore-application/ with -javaagent:lib/kieker-1.9_aspectj.jar and having no aop.xml in the classpath
1. Results in the following monitoring log:

avhAndrè van Hoorn-ThinkPad-RSS:0:~/svn_work/phd_vanhoorn/talks/201405-KiekerLectureUPavia/kieker-1.9-release/kieker-1.9-bin $ cat /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker-20140519-204302970-UTC-000-Thread-1.dat 
$0;1400532182969604898;1.9;KIEKER-SINGLETON;avh-ThinkPad-RSS;1;false;0;NANOSECONDS;1
$1;1400532182966555136;-4859590388291207168;1;<no-session-id>;avh-ThinkPad-RSS;-4859590388291207168;-1
$2;1400532182980275191;1400532182980237475;-4859590388291207168;0;public static void kieker.examples.userguide.ch2bookstore.BookstoreStarter.main(java.lang.String[]);kieker.examples.userguide.ch2bookstore.BookstoreStarter;0
$2;1400532183006793865;1400532183006777961;-4859590388291207168;1;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$3;1400532183010839058;1400532183010818349;-4859590388291207168;2;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$2;1400532183011070247;1400532183011065800;-4859590388291207168;3;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$3;1400532183011082057;1400532183011079140;-4859590388291207168;4;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$2;1400532183011199165;1400532183011195978;-4859590388291207168;5;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$3;1400532183011208895;1400532183011206342;-4859590388291207168;6;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$2;1400532183011328103;1400532183011324944;-4859590388291207168;7;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$3;1400532183011337519;1400532183011334854;-4859590388291207168;8;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$2;1400532183011452059;1400532183011448945;-4859590388291207168;9;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$3;1400532183011475657;1400532183011473176;-4859590388291207168;10;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371
$3;1400532183011517577;1400532183011511692;-4859590388291207168;11;public static void kieker.examples.userguide.ch2bookstore.BookstoreStarter.main(java.lang.String[]);kieker.examples.userguide.ch2bookstore.BookstoreStarter;0
avhAndrè van Hoorn-ThinkPad-RSS:0:~/svn_work/phd_vanhoorn/talks/201405-KiekerLectureUPavia/kieker-1.9-release/kieker-1.9-bin $ cat /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker.map 
$0=kieker.common.record.misc.KiekerMetadataRecord
$1=kieker.common.record.flow.trace.TraceMetadata
$2=kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent
$3=kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent

1. Running Trace Analysis (Already suprising that only one trace reconstructed ...)

avhAndrè van Hoorn-ThinkPad-RSS:1:~/svn_work/phd_vanhoorn/talks/201405-KiekerLectureUPavia/kieker-1.9-release/kieker-1.9-bin $ bin/trace-analysis.sh -i /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/ -o /home/avh/svn_work/phd_vanhoorn/talks/201405-KiekerLectureUPavia/kieker-1.9-release/kieker-1.9-bin/out/ --plot-Deployment-Component-Dependency-Graph
#
# Configuration
--inputdirs: /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/
--outputdir: /home/avh/svn_work/phd_vanhoorn/talks/201405-KiekerLectureUPavia/kieker-1.9-release/kieker-1.9-bin/out//
--output-filename-prefix: 
--plot-Deployment-Sequence-Diagrams: false
--plot-Assembly-Sequence-Diagrams: false
--plot-Deployment-Component-Dependency-Graph: true
--plot-Assembly-Component-Dependency-Graph: false
--plot-Container-Dependency-Graph: false
--plot-Deployment-Operation-Dependency-Graph: false
--plot-Assembly-Operation-Dependency-Graph: false
--plot-Aggregated-Deployment-Call-Tree: false
--plot-Aggregated-Assembly-Call-Tree: false
--plot-Call-Trees: false
--print-Message-Traces: false
--print-Execution-Traces: false
--print-invalid-Execution-Traces: false
--print-System-Model: false
--print-Deployment-Equivalence-Classes: false
--print-Assembly-Equivalence-Classes: false
--select-traces: <select all>
--ignore-invalid-traces: false
--max-trace-duration: 600000 ms
--ignore-executions-before-date: Thu, 1 Jan 1970 00:00:00 +0000 (UTC) (Thu, 1 Jan 1970 01:00:00 +0100 (local time))
--ignore-executions-after-date: Fri, 11 Apr 2262 23:47:16 +0000 (UTC) (Sat, 12 Apr 2262 01:47:16 +0200 (local time))
--short-labels: false
--include-self-loops: false
--traceColoring: 
--addDescriptions: 

#
# Plugin: SystemModel2FileFilter-7
Wrote HTML output of system model to file '/home/avh/svn_work/phd_vanhoorn/talks/201405-KiekerLectureUPavia/kieker-1.9-release/kieker-1.9-bin/out/system-entities.html'

#
# Plugin: ComponentDependencyGraphAllocationFilter-6
Trace processing summary: 1 total; 1 succeeded; 0 failed.

#
# Plugin: Trace reconstruction (execution records -> execution traces)
Trace processing summary: 0 total; 0 succeeded; 0 failed.

#
# Plugin: Trace reconstruction (event records -> event record traces)
Trace processing summary: 1 total; 1 succeeded; 0 failed.

#
# Plugin: Trace reconstruction (event record traces -> execution traces)
Trace processing summary: 1 total; 1 succeeded; 0 failed.

Analysis completed successfully

See 'kieker.log' for details

real    0m0.784s
user    0m1.144s
sys     0m0.060s

1. The kieker-log reals that unsupported records written:

avhAndrè van Hoorn-ThinkPad-RSS:0:~/svn_work/phd_vanhoorn/talks/201405-KiekerLectureUPavia/kieker-1.9-release/kieker-1.9-bin $ cat kieker.log 
May 19, 2014 11:07:50 PM kieker.tools.traceAnalysis.TraceAnalysisTool mainHelper
INFO: Argument list: [-i, /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/, -o, /home/avh/svn_work/phd_vanhoorn/talks/201405-KiekerLectureUPavia/kieker-1.9-release/kieker-1.9-bin/out/, --plot-Deployment-Component-Dependency-Graph]
May 19, 2014 11:07:50 PM kieker.analysis.plugin.reader.filesystem.FSDirectoryReader run
INFO: < Loading /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker-20140519-204302970-UTC-000-Thread-1.dat
May 19, 2014 11:07:50 PM kieker.analysis.AnalysisController handleKiekerMetadataRecord
INFO: Kieker metadata: version='1.9', controllerName='KIEKER-SINGLETON', hostname='avh-ThinkPad-RSS', experimentId='1', debugMode='false', timeOffset='0', timeUnit='NANOSECONDS', numberOfRecords='1'
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 19, 2014 11:07:50 PM kieker.analysis.AnalysisController terminate
INFO: Terminating analysis.
May 19, 2014 11:07:50 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.FSReader-2 terminate
INFO: Shutting down reader.
May 19, 2014 11:07:51 PM kieker.tools.traceAnalysis.TraceAnalysisTool dispatchTasks
INFO: Saved analysis configuration to file '/home/avh/svn_work/phd_vanhoorn/talks/201405-KiekerLectureUPavia/kieker-1.9-release/kieker-1.9-bin/out/traceAnalysis.kax'

1. The generated diagrams include only the Entry node.

rju commented 6 days ago

author Jan Waller -- Mon, 19 May 2014 23:16:11 +0200

The event parts are not needed, this could be changed. But the tool should be able to handle them without problems. A fallback to the superclass does not seem to work...

rju commented 6 days ago

author nils-christian -- Tue, 20 May 2014 10:27:21 +0200

Since 6bd9ddcfb57129328f2cd0de3eebfeaa72f5cd61 we now use the "more lightweight" probe, which does not produce the event parts.

However, the fallback issue is currently handled by Jan.

rju commented 6 days ago

author Jan Waller -- Tue, 20 May 2014 10:29:51 +0200

Should be fixed in f01dca92485980e6a4d1e50ddc03e3924efc4b43

André van Hoorn: can you confirm with the old default aop.xml?

rju commented 6 days ago

author André van Hoorn -- Tue, 20 May 2014 14:49:47 +0200

Replying to [jwa|comment:3]:
> Should be fixed in f01dca92485980e6a4d1e50ddc03e3924efc4b43
>
> André van Hoorn: can you confirm with the old default aop.xml?

Jan Waller: What exactly should I confirm?

rju commented 6 days ago

author Jan Waller -- Tue, 20 May 2014 14:53:05 +0200

That your old log files can now be analyzed correctly.

rju commented 6 days ago

author André van Hoorn -- Tue, 20 May 2014 15:53:51 +0200

Replying to [jwa|comment:5]:
> That your old log files can now be analyzed correctly.

Not really: 

avhAndrè van Hoorn-ThinkPad-RSS:0:~/git_work/kieker <master> $ rm out/*
avhAndrè van Hoorn-ThinkPad-RSS:0:~/git_work/kieker <master> $ bin/trace-analysis.sh -i /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/ -o out/ --plot-Deployment-Component-Dependency-Graph

Analysis completed successfully

See 'kieker.log' for details

real    0m0.695s
user    0m1.184s
sys     0m0.068s
avhAndrè van Hoorn-ThinkPad-RSS:0:~/git_work/kieker <master> $ cat kieker.log 
May 20, 2014 3:49:40 PM kieker.tools.traceAnalysis.TraceAnalysisTool mainHelper
INFO: Argument list: [-i, /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/, -o, out/, --plot-Deployment-Component-Dependency-Graph]
May 20, 2014 3:49:40 PM kieker.analysis.plugin.reader.filesystem.FSDirectoryReader run
INFO: < Loading /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker-20140519-204302970-UTC-000-Thread-1.dat
May 20, 2014 3:49:40 PM kieker.analysis.AnalysisController handleKiekerMetadataRecord
INFO: Kieker metadata: version='1.9', controllerName='KIEKER-SINGLETON', hostname='avh-ThinkPad-RSS', experimentId='1', debugMode='false', timeOffset='0', timeUnit='NANOSECONDS', numberOfRecords='1'
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.BeforeOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.Trace reconstruction (event record traces -> execution traces) inputTraceEvents
WARNING: Events of type 'kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent' are currently not handled and ignored.
May 20, 2014 3:49:40 PM kieker.analysis.AnalysisController terminate
INFO: Terminating analysis.
May 20, 2014 3:49:40 PM kieker.analysis.analysisComponent.AbstractAnalysisComponent.FSReader-2 terminate
INFO: Shutting down reader.
May 20, 2014 3:49:41 PM kieker.tools.traceAnalysis.TraceAnalysisTool dispatchTasks
INFO: Saved analysis configuration to file '/home/avh/git_work/kieker/out/traceAnalysis.kax'
May 20, 2014 3:50:50 PM kieker.tools.traceAnalysis.TraceAnalysisTool start
INFO: Argument list: [-i, /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/, -o, out/, --plot-Deployment-Component-Dependency-Graph]
May 20, 2014 3:50:50 PM kieker.analysis.plugin.reader.filesystem.FSDirectoryReader run
INFO: < Loading /tmp/kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker-20140519-204302970-UTC-000-Thread-1.dat
May 20, 2014 3:50:50 PM kieker.analysis.AnalysisController handleKiekerMetadataRecord
INFO: Kieker metadata: version='1.9', controllerName='KIEKER-SINGLETON', hostname='avh-ThinkPad-RSS', experimentId='1', debugMode='false', timeOffset='0', timeUnit='NANOSECONDS', numberOfRecords='1'
May 20, 2014 3:50:50 PM kieker.tools.traceAnalysis.filter.flow.TraceEventRecords2ExecutionAndMessageTraceFilter (Trace reconstruction (event record traces -> execution traces)) inputTraceEvents
SEVERE: Failed to reconstruct trace.
kieker.tools.traceAnalysis.filter.traceReconstruction.InvalidTraceException: Didn't find corresponding kieker.common.record.flow.trace.operation.BeforeOperationEvent for kieker.common.record.flow.trace.operation.object.AfterOperationObjectEvent 1400532183010839058;1400532183010818349;-4859590388291207168;2;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371 (found: 1400532183006793865;1400532183006777961;-4859590388291207168;1;public void kieker.examples.userguide.ch2bookstore.Bookstore.searchBook();kieker.examples.userguide.ch2bookstore.Bookstore;845163371).
        at kieker.tools.traceAnalysis.filter.flow.TraceEventRecords2ExecutionAndMessageTraceFilter$TraceEventRecordHandler.handleAfterEvent(TraceEventRecords2ExecutionAndMessageTraceFilter.java:399)
        at kieker.tools.traceAnalysis.filter.flow.TraceEventRecords2ExecutionAndMessageTraceFilter$TraceEventRecordHandler.handleAfterOperationEvent(TraceEventRecords2ExecutionAndMessageTraceFilter.java:432)
        at kieker.tools.traceAnalysis.filter.flow.TraceEventRecords2ExecutionAndMessageTraceFilter.inputTraceEvents(TraceEventRecords2ExecutionAndMessageTraceFilter.java:162)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at kieker.analysis.plugin.AbstractPlugin.deliver(AbstractPlugin.java:212)
        at kieker.analysis.plugin.filter.flow.EventRecordTraceReconstructionFilter.newEvent(EventRecordTraceReconstructionFilter.java:236)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at kieker.analysis.plugin.AbstractPlugin.deliver(AbstractPlugin.java:212)
        at kieker.analysis.plugin.filter.select.TraceIdFilter.inputTraceEvent(TraceIdFilter.java:150)
        at kieker.analysis.plugin.filter.select.TraceIdFilter.inputCombined(TraceIdFilter.java:125)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at kieker.analysis.plugin.AbstractPlugin.deliver(AbstractPlugin.java:212)
        at kieker.analysis.plugin.filter.select.TimestampFilter.inputTraceEvent(TimestampFilter.java:181)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at kieker.analysis.plugin.AbstractPlugin.deliver(AbstractPlugin.java:212)
        at kieker.analysis.plugin.filter.forward.StringBufferFilter.inputEvent(StringBufferFilter.java:132)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at kieker.analysis.plugin.AbstractPlugin.deliver(AbstractPlugin.java:212)
        at kieker.analysis.plugin.reader.filesystem.FSReader.read(FSReader.java:144)
        at kieker.analysis.AnalysisController$1.run(AnalysisController.java:468)
        at java.lang.Thread.run(Thread.java:662)
May 20, 2014 3:50:50 PM kieker.analysis.AnalysisController terminate
INFO: Terminating analysis.
May 20, 2014 3:50:50 PM kieker.analysis.plugin.reader.filesystem.FSReader (FSReader-2) terminate
INFO: Shutting down reader.
May 20, 2014 3:50:51 PM kieker.tools.traceAnalysis.TraceAnalysisTool dispatchTasks
INFO: Saved analysis configuration to file '/home/avh/git_work/kieker/out/traceAnalysis.kax'

Attached, you'll find the monitoring log: attachment:kieker-20140519-204302923-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON.zip

Makes sense to extend our trace reconstruction unit tests.

rju commented 6 days ago

author Jan Waller -- Tue, 20 May 2014 16:55:47 +0200

7cca38c72f9670212f7b70ae4fd2f5d91929c4fb

The test case is now working for me. Hopefully, all instances of "ignoring record inheritance" are now removed.

rju commented 6 days ago

author André van Hoorn -- Tue, 20 May 2014 17:04:16 +0200

Replying to [jwa|comment:7]:
> 7cca38c72f9670212f7b70ae4fd2f5d91929c4fb
>
> The test case is now working for me. Hopefully, all instances of "ignoring record inheritance" are now removed.

Yes, I can confirm this.

We should have a Unit test including these records.

rju commented 6 days ago

author Jan Waller -- Tue, 20 May 2014 17:06:57 +0200

Replying to [avh|comment:8]:
> We should have a Unit test including these records.

yes ...

rju commented 6 days ago

author nils-christian -- Thu, 21 Aug 2014 13:54:40 +0200

Instead of adding a JUnit test, I recommend to use the existing trace analysis test script of the nightly build for this task. I added some flow records with corresponding expected output plots in a branch (KIEK-1119-flow-trace-analysis).

André: Could you modify your nightly test script to take the results of the new plot script into account?

rju commented 6 days ago

author André van Hoorn -- Thu, 2 Oct 2014 10:18:36 +0200

Replying to [nie|comment:11]:
> Instead of adding a JUnit test, I recommend to use the existing trace analysis test script of the nightly build for this task. I added some flow records with corresponding expected output plots in a branch (KIEK-1119-flow-trace-analysis).
>
> André: Could you modify your nightly test script to take the results of the new plot script into account?

Remarks:


- Reference plots with response times to be (re-)enabled [version includes bug with line break in generated dot|branch]
- Regenerated reference plots and files due to different orders in dot files under *NIX. Compared files and PDFs with Nils's reference results.

rju commented 6 days ago

author André van Hoorn -- Thu, 2 Oct 2014 10:25:19 +0200

After having re-executed the reference plots with the latest version from master it can be observed that something with the reconstruction of event-based signatures seems to be broken in the meantime. This seems related to the problems revealed in KIEKER-1194 Done ([comment:7|/trac/ticket/1295#comment:7]).

Reference plot:

Plot created from master:

rju commented 6 days ago

author Jan Waller -- Fri, 3 Oct 2014 00:43:33 +0200

I think I found the problem:
Something got switched around somewhere?
The probes write ...,class,operation but the records are actually ...,operation,class

This was fine in 1.9.
Why is it not checked in unit tests?

Concerning this ticket: the testdata must be recreated with the fixed probes.

rju commented 6 days ago

author Jan Waller -- Fri, 3 Oct 2014 00:48:15 +0200

The change had been done by Reiner with the record generation code?

rju commented 6 days ago

author André van Hoorn -- Fri, 3 Oct 2014 15:20:41 +0200

Thanks, Jan. That seems to make sense!

Reiner Jung: There seems to be another switched attribute pair in the (generated) event records. Details above. Could you double-check this? Also, as mentioned by Jan: It's strange that this hasn't been revealed by the tests.

rju commented 6 days ago

author André van Hoorn -- Fri, 3 Oct 2014 15:23:45 +0200

Replying to [jwa|comment:18]:

> Concerning this ticket: the testdata must be recreated with the fixed probes.

Jan, does this mean that the current version of records in the trunk is fine and just the testdata (created in a branch) is wrong, i.e., has to be regenerated with that version?

rju commented 6 days ago

author Jan Waller -- Fri, 3 Oct 2014 18:48:53 +0200

Yes, the records did not change, but the probes did.

rju commented 6 days ago

author rju -- Fri, 3 Oct 2014 19:55:46 +0200

I'll look into it on monday when I'm back from Spain.

rju commented 6 days ago

author nils-christian -- Wed, 8 Oct 2014 12:24:42 +0200

I updated the generated records and plots in 407479ee7f6dfa463b3b2fdac13a9cd5e92584b8 and fixed the remaining probes in 9795d96a79f1a477fcf45107c91a939fe94f1f56. Output of the current master:

rju commented 6 days ago

author André van Hoorn -- Wed, 8 Oct 2014 12:27:35 +0200

Replying to [nie|comment:24]:
> I updated the generated records and plots in 407479ee7f6dfa463b3b2fdac13a9cd5e92584b8 and fixed the remaining probes in 9795d96a79f1a477fcf45107c91a939fe94f1f56. Output of the current master:
>
>

Just to make sure: what's the reason that the probes need to be fixed?

rju commented 6 days ago

author rju -- Wed, 8 Oct 2014 12:42:37 +0200

Actually that was a revert of a code change done previously to "fix" an issue with changed parameter ordering which affected some record types. As we now have checks in place to ensure that the parameter ordering in records is evaluated against the previous release implementation and the record structure could then be repaired, those previous fixes had to be reverted. However, some of them have not been reverted (actually, I missed them, as all normal checks worked perfectly. Sorry for that).

rju commented 6 days ago

author André van Hoorn -- Thu, 9 Oct 2014 17:42:12 +0200

Thanks! So this ticket can be closed, right?