search

kieker-monitoring / kieker

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

[KIEKER-967] Feature wish: Accelaration factor for real time replayer #963

Open rju opened 2 weeks ago

rju commented 2 weeks ago

JIRA Issue: KIEKER-967 Feature wish: Accelaration factor for real time replayer Original Reporter: Andre van Hoorn

Makes sense, for instance, for data recorded over a large time period (let's say months/years) sometimes including only sparse monitoring events (e.g., every hour). The current implementation has an acceleration factor of 1 (which would then be the default).

Checklist:

rju commented 1 week ago

author André van Hoorn -- Tue, 3 Sep 2013 17:28:45 +0200

Added acceleration factor and corresponding tests in

The RealtimeRecordDelayFilter now expects a double configuration property as acceleration factor. Default 1.0 means no acceleration/slow down. As examples,

To be integrated as parameter into the cmdl tool.

rju commented 1 week ago

author André van Hoorn -- Wed, 4 Sep 2013 17:58:24 +0200

> To be integrated as parameter into the cmdl tool.

Done in changeset:9db5c3b281e33c9c4b9d99b97e29fc210b7b707f/kieker-git

Test:

1. Generate data using the Sigar example

avhAndrè van Hoorn-ThinkPad-RSS:0:/tmp/kieker-1.8-SNAPSHOT/examples/userguide/appendix-Sigar $ ant run-monitoring
...

     [java]             Finished: 'false'; Writing to Directory: '/tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON'
     [java] Sampling Controller: Periodic Sensor available: Poolsize: '0'; Scheduled Tasks: '0'
     [java] Sep 4, 2013 5:47:07 PM kieker.monitoring.core.controller.MonitoringController cleanup
     [java] INFO: Shutting down Monitoring Controller Terminating
     [java] (KIEKER-SINGLETON)
     [java] Sep 4, 2013 5:47:07 PM kieker.monitoring.writer.AbstractAsyncWriter terminate
     [java] INFO: Shutting down writers.
     [java] Sep 4, 2013 5:47:07 PM kieker.monitoring.writer.AbstractAsyncWriter terminate
     [java] INFO: Writer shutdown complete.

BUILD SUCCESSFUL
Total time: 31 seconds

2. Determine time of first and last record

avhAndrè van Hoorn-ThinkPad-RSS:0:/tmp/kieker-1.8-SNAPSHOT $ head -n 1  /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker-20130904-154640110-UTC-000-Thread-1.dat 
$0;1378309600109928882;1.8-SNAPSHOT;KIEKER-SINGLETON;avh-ThinkPad-RSS;1;false;0;NANOSECONDS;1
avhAndrè van Hoorn-ThinkPad-RSS:0:/tmp/kieker-1.8-SNAPSHOT $ tail -n 1  /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker-20130904-154640110-UTC-000-Thread-1.dat 
$2;1378309624604954000;1378309624604944033;avh-ThinkPad-RSS;12288753664;4145954816;8142798848;12565082112;25391104;12539691008
avhAndrè van Hoorn-ThinkPad-RSS:0:/tmp/kieker-1.8-SNAPSHOT $ bin/convertLoggingTimestamp.sh -t 1378309600109928882 13783096246049540001378309600109928882: Wed, 4 Sep 2013 15:46:40 +0000 (UTC) (Wed, 4 Sep 2013 17:46:40 +0200 (local time))
1378309624604954000: Wed, 4 Sep 2013 15:47:04 +0000 (UTC) (Wed, 4 Sep 2013 17:47:04 +0200 (local time))

-> ~ 25 seconds

3. Replay with different acceleration factors: 

avhAndrè van Hoorn-ThinkPad-RSS:1:/tmp/kieker-1.8-SNAPSHOT $ time bin/logReplay.sh -i /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/ -r true

real    0m24.716s
user    0m24.762s
sys     0m0.032s
avhAndrè van Hoorn-ThinkPad-RSS:0:/tmp/kieker-1.8-SNAPSHOT $ time bin/logReplay.sh -a 0.5 -i /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/ -r true

real    0m49.192s
user    0m49.219s
sys     0m0.032s
avhAndrè van Hoorn-ThinkPad-RSS:0:/tmp/kieker-1.8-SNAPSHOT $ time bin/logReplay.sh -a 2 -i /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/ -r true

real    0m12.491s
user    0m12.577s
sys     0m0.024s

4. Inspect kieker.log

avhAndrè van Hoorn-ThinkPad-RSS:130:/tmp/kieker-1.8-SNAPSHOT $ cat kieker.log 
Sep 4, 2013 5:47:56 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: Keeping original logging timestamps: true
Sep 4, 2013 5:47:56 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: inputDirs: /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/
Sep 4, 2013 5:47:56 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: Replaying in realtime mode
Sep 4, 2013 5:47:56 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: Using 1 realtime worker thread
Sep 4, 2013 5:47:56 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter main
INFO: Replaying log data in real time
Sep 4, 2013 5:47:56 PM kieker.tools.logReplayer.AbstractLogReplayer <init>
INFO: No path to a 'monitoring.properties' passed; default configuration will be used.
Sep 4, 2013 5:47:56 PM kieker.tools.logReplayer.filter.MonitoringRecordLoggerFilter <init>
INFO: No path to a 'monitoring.properties' file passed; using default configuration
Sep 4, 2013 5:47:56 PM kieker.monitoring.core.controller.MonitoringController createInstance
INFO: Current State of kieker.monitoring (1.8-SNAPSHOT) Status: 'enabled'
        Name: 'KIEKER'; Hostname: 'avh-ThinkPad-RSS'; experimentID: '1'
JMXController: JMX disabled
RegistryController: 0 strings registered.
TimeSource: 'kieker.monitoring.timer.SystemNanoTimer'
        Time in nanoseconds (with nanoseconds precision) since Thu Jan 01 01:00:00 CET 1970'
ProbeController: disabled
WriterController:
        Number of Inserts: '0'
        Automatic assignment of logging timestamps: 'false'
Writer: 'kieker.monitoring.writer.filesystem.AsyncFsWriter'
        Configuration:
                kieker.monitoring.writer.filesystem.AsyncFsWriter.flush='true'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.maxLogSize='-1'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.storeInJavaIoTmpdir='true'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.QueueFullBehavior='0'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.MaxShutdownDelay='-1'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.maxEntriesInFile='25000'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.bufferSize='8192'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.maxLogFiles='-1'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.customStoragePath='.'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.QueueSize='10000'
        Records lost: 0
        Writer Threads (1): 
                Finished: 'false'; Writing to Directory: '/tmp/kieker-20130904-154756603-UTC-avh-ThinkPad-RSS-KIEKER'
Sampling Controller: Periodic Sensor available: Poolsize: '0'; Scheduled Tasks: '0'
Sep 4, 2013 5:47:56 PM kieker.analysis.plugin.reader.filesystem.FSDirectoryReader run
INFO: < Loading /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker-20130904-154640110-UTC-000-Thread-1.dat
Sep 4, 2013 5:47:56 PM kieker.analysis.AnalysisController handleKiekerMetadataRecord
INFO: Kieker metadata: version='1.8-SNAPSHOT', controllerName='KIEKER-SINGLETON', hostname='avh-ThinkPad-RSS', experimentId='1', debugMode='false', timeOffset='0', timeUnit='NANOSECONDS', numberOfRecords='1'
Sep 4, 2013 5:47:56 PM kieker.analysis.AnalysisController terminate
INFO: Terminating analysis.
Sep 4, 2013 5:47:56 PM kieker.analysis.plugin.reader.filesystem.FSReader terminate
INFO: Shutting down reader.
Sep 4, 2013 5:47:56 PM kieker.analysis.plugin.filter.forward.RealtimeRecordDelayFilter terminate
INFO: Awaiting termination delay of 29 seconds ...
Sep 4, 2013 5:48:21 PM kieker.monitoring.core.controller.MonitoringController cleanup
INFO: Shutting down Monitoring Controller (KIEKER)
Sep 4, 2013 5:48:21 PM kieker.monitoring.writer.AbstractAsyncWriter terminate
INFO: Shutting down writers.
Sep 4, 2013 5:48:21 PM kieker.monitoring.writer.AbstractAsyncWriter terminate
INFO: Writer shutdown complete.
Sep 4, 2013 5:49:04 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: Keeping original logging timestamps: true
Sep 4, 2013 5:49:04 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: inputDirs: /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/
Sep 4, 2013 5:49:04 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: Replaying in realtime mode
Sep 4, 2013 5:49:04 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: Using 1 realtime worker thread
Sep 4, 2013 5:49:04 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter main
INFO: Replaying log data in real time
Sep 4, 2013 5:49:04 PM kieker.tools.logReplayer.AbstractLogReplayer <init>
INFO: No path to a 'monitoring.properties' passed; default configuration will be used.
Sep 4, 2013 5:49:04 PM kieker.tools.logReplayer.filter.MonitoringRecordLoggerFilter <init>
INFO: No path to a 'monitoring.properties' file passed; using default configuration
Sep 4, 2013 5:49:04 PM kieker.monitoring.core.controller.MonitoringController createInstance
INFO: Current State of kieker.monitoring (1.8-SNAPSHOT) Status: 'enabled'
        Name: 'KIEKER'; Hostname: 'avh-ThinkPad-RSS'; experimentID: '1'
JMXController: JMX disabled
RegistryController: 0 strings registered.
TimeSource: 'kieker.monitoring.timer.SystemNanoTimer'
        Time in nanoseconds (with nanoseconds precision) since Thu Jan 01 01:00:00 CET 1970'
ProbeController: disabled
WriterController:
        Number of Inserts: '0'
        Automatic assignment of logging timestamps: 'false'
Writer: 'kieker.monitoring.writer.filesystem.AsyncFsWriter'
        Configuration:
                kieker.monitoring.writer.filesystem.AsyncFsWriter.flush='true'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.maxLogSize='-1'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.storeInJavaIoTmpdir='true'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.QueueFullBehavior='0'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.MaxShutdownDelay='-1'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.maxEntriesInFile='25000'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.bufferSize='8192'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.maxLogFiles='-1'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.customStoragePath='.'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.QueueSize='10000'
        Records lost: 0
        Writer Threads (1): 
                Finished: 'false'; Writing to Directory: '/tmp/kieker-20130904-154904270-UTC-avh-ThinkPad-RSS-KIEKER'
Sampling Controller: Periodic Sensor available: Poolsize: '0'; Scheduled Tasks: '0'
Sep 4, 2013 5:49:04 PM kieker.analysis.plugin.reader.filesystem.FSDirectoryReader run
INFO: < Loading /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker-20130904-154640110-UTC-000-Thread-1.dat
Sep 4, 2013 5:49:04 PM kieker.analysis.AnalysisController handleKiekerMetadataRecord
INFO: Kieker metadata: version='1.8-SNAPSHOT', controllerName='KIEKER-SINGLETON', hostname='avh-ThinkPad-RSS', experimentId='1', debugMode='false', timeOffset='0', timeUnit='NANOSECONDS', numberOfRecords='1'
Sep 4, 2013 5:49:04 PM kieker.analysis.AnalysisController terminate
INFO: Terminating analysis.
Sep 4, 2013 5:49:04 PM kieker.analysis.plugin.reader.filesystem.FSReader terminate
INFO: Shutting down reader.
Sep 4, 2013 5:49:04 PM kieker.analysis.plugin.filter.forward.RealtimeRecordDelayFilter terminate
INFO: Awaiting termination delay of 53 seconds ...
Sep 4, 2013 5:49:53 PM kieker.monitoring.core.controller.MonitoringController cleanup
INFO: Shutting down Monitoring Controller (KIEKER)
Sep 4, 2013 5:49:53 PM kieker.monitoring.writer.AbstractAsyncWriter terminate
INFO: Shutting down writers.
Sep 4, 2013 5:49:53 PM kieker.monitoring.writer.AbstractAsyncWriter terminate
INFO: Writer shutdown complete.
Sep 4, 2013 5:50:25 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: Keeping original logging timestamps: true
Sep 4, 2013 5:50:25 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: inputDirs: /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/
Sep 4, 2013 5:50:25 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: Replaying in realtime mode
Sep 4, 2013 5:50:25 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter initFromArgs
INFO: Using 1 realtime worker thread
Sep 4, 2013 5:50:25 PM kieker.tools.logReplayer.FilesystemLogReplayerStarter main
INFO: Replaying log data in real time
Sep 4, 2013 5:50:25 PM kieker.tools.logReplayer.AbstractLogReplayer <init>
INFO: No path to a 'monitoring.properties' passed; default configuration will be used.
Sep 4, 2013 5:50:25 PM kieker.tools.logReplayer.filter.MonitoringRecordLoggerFilter <init>
INFO: No path to a 'monitoring.properties' file passed; using default configuration
Sep 4, 2013 5:50:25 PM kieker.monitoring.core.controller.MonitoringController createInstance
INFO: Current State of kieker.monitoring (1.8-SNAPSHOT) Status: 'enabled'
        Name: 'KIEKER'; Hostname: 'avh-ThinkPad-RSS'; experimentID: '1'
JMXController: JMX disabled
RegistryController: 0 strings registered.
TimeSource: 'kieker.monitoring.timer.SystemNanoTimer'
        Time in nanoseconds (with nanoseconds precision) since Thu Jan 01 01:00:00 CET 1970'
ProbeController: disabled
WriterController:
        Number of Inserts: '0'
        Automatic assignment of logging timestamps: 'false'
Writer: 'kieker.monitoring.writer.filesystem.AsyncFsWriter'
        Configuration:
                kieker.monitoring.writer.filesystem.AsyncFsWriter.flush='true'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.maxLogSize='-1'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.storeInJavaIoTmpdir='true'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.QueueFullBehavior='0'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.MaxShutdownDelay='-1'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.maxEntriesInFile='25000'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.bufferSize='8192'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.maxLogFiles='-1'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.customStoragePath='.'
                kieker.monitoring.writer.filesystem.AsyncFsWriter.QueueSize='10000'
        Records lost: 0
        Writer Threads (1): 
                Finished: 'false'; Writing to Directory: '/tmp/kieker-20130904-155025283-UTC-avh-ThinkPad-RSS-KIEKER'
Sampling Controller: Periodic Sensor available: Poolsize: '0'; Scheduled Tasks: '0'
Sep 4, 2013 5:50:25 PM kieker.analysis.plugin.reader.filesystem.FSDirectoryReader run
INFO: < Loading /tmp/kieker-20130904-154637543-UTC-avh-ThinkPad-RSS-KIEKER-SINGLETON/kieker-20130904-154640110-UTC-000-Thread-1.dat
Sep 4, 2013 5:50:25 PM kieker.analysis.AnalysisController handleKiekerMetadataRecord
INFO: Kieker metadata: version='1.8-SNAPSHOT', controllerName='KIEKER-SINGLETON', hostname='avh-ThinkPad-RSS', experimentId='1', debugMode='false', timeOffset='0', timeUnit='NANOSECONDS', numberOfRecords='1'
Sep 4, 2013 5:50:25 PM kieker.analysis.AnalysisController terminate
INFO: Terminating analysis.
Sep 4, 2013 5:50:25 PM kieker.analysis.plugin.reader.filesystem.FSReader terminate
INFO: Shutting down reader.
Sep 4, 2013 5:50:25 PM kieker.analysis.plugin.filter.forward.RealtimeRecordDelayFilter terminate
INFO: Awaiting termination delay of 17 seconds ...
Sep 4, 2013 5:50:37 PM kieker.monitoring.core.controller.MonitoringController cleanup
INFO: Shutting down Monitoring Controller (KIEKER)
Sep 4, 2013 5:50:37 PM kieker.monitoring.writer.AbstractAsyncWriter terminate
INFO: Shutting down writers.
Sep 4, 2013 5:50:37 PM kieker.monitoring.writer.AbstractAsyncWriter terminate
INFO: Writer shutdown complete.