search

domgiles / swingbench-public

Public repository for swingbench to support the creation of issues and a location to download latest builds
73 stars 20 forks source link

No CPU statistics in the results file of Charbench when specifying a run time #9

Open RedFrogChopstick opened 4 years ago

RedFrogChopstick commented 4 years ago

Hello Mister Giles,

I tried contacting you via the "comments" section of your website but it seems to have been disabled or broken.

I am currently trying to automate some testing with Charbench to collect stats over a longer period of time and I noticed in the results files that for some reason when I specify a run time for the tests the results files only contain TPSReadings in the BenchmarkMetrics section. I already tried using the -f flag and specifying a start and end time for the measurements but to no avail.

Is it a bug or is the behavior intentional and if so is there a workaround?

With best regards, Maximilian Sauer

RedFrogChopstick commented 4 years ago

I just realized that you are asking for more information in the README.md. Sorry for not adding it sooner.

22:21:48 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Swingbench Version 2.6.0.1124 22:21:48 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Operating System: Linux 22:21:48 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Available processors (cores): 2 22:21:48 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Free memory (bytes): 498681248 22:21:48 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Maximum memory (bytes): 954728448 22:21:48 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Total memory available to JVM (bytes): 514850816 22:21:48 FINE [8] com.dom.benchmarking.swingbench.CharBench parseConfig() Started CharBench 22:21:49 FINE [8] com.dom.benchmarking.swingbench.configuration.Configuration initConfiguration() Initialising configuration : Stress Test 22:21:49 FINE [8] com.dom.benchmarking.swingbench.configuration.Configuration initConfiguration() Overview 22:21:49 FINE [8] com.dom.benchmarking.swingbench.configuration.Configuration initConfiguration() Connection Refresh set to : 0 22:21:49 FINE [8] com.dom.benchmarking.swingbench.configuration.Configuration initConfiguration() Username = soe, Password = enc(cw4Xx9RgsQA=), Connectstring = jdbc:oracle:thin:@XXX:1521:oracl 22:21:49 FINE [8] com.dom.benchmarking.swingbench.frontend.CommandLineProcessor overrideConfig() Overriding config with command line parameters 22:21:49 FINE [8] com.dom.benchmarking.swingbench.frontend.CommandLineProcessor overrideConfig() Completed overrideConfig() 22:21:49 FINE [8] com.dom.benchmarking.swingbench.CharBench () Verbose outputfile : null Author : Dominic Giles Version : 2.6.0.1124

Results will be written to ./myresults.xml. 22:21:49 FINE [12] com.dom.benchmarking.swingbench.CharBench run() Beginning Run 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource () Level of statistics = simple 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource init() Initilization of swingbench datasource 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource init() Active Transaction = 4 22:21:49 FINE [12] com.dom.benchmarking.swingbench.CharBench run() Charbench starting in manual mode Hit Return to Terminate Run... 22:21:49 FINE [12] com.dom.benchmarking.swingbench.CharBench run() userSessionManager.start() invoked 22:21:49 FINE [12] com.dom.benchmarking.swingbench.CharBench run() Entering main loop Time Users TPM TPS 22:21:49 FINE [12] com.dom.benchmarking.swingbench.CharBench run() StateChange 22:21:49 FINE [12] com.dom.benchmarking.swingbench.CharBench isRunning() isRunning returned true 22:21:49 FINE [12] com.dom.benchmarking.swingbench.CharBench run() State changed to running in run() 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSessionManager init() Initilization UserSessionManager() 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSessionManager initSessions() Initialising all of the sessions, creating 1 new sessions 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () STDebugging = false 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () STConnectionTolerance = 10000 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () MaximumTxRetries = -1 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () STRetriesInterval = 1000 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () STJitter = 0 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () maxInterDelay = 0 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () maxIntraDelay = 0 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () minInterDelay = 0 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () minIntraDelay = 0 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () CommitClientSide = true 22:21:49 FINE [12] com.dom.benchmarking.swingbench.CharBench run() userSessionManager.init completed 22:21:49 FINE [12] com.dom.benchmarking.swingbench.CharBench run() listeners added 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource setStartedRun() Start of benchmark : setStartedRun() 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource setStartedRun() Attempting to connect with XXX 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource registerWithSystemMonitor() Attempting to register with System Monitor 22:21:49 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource registerWithSystemMonitor() Attempting to connect to SystemMonitor : oracle 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Connecting to XXX port 22 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Connection established 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Remote version string: SSH-2.0-OpenSSH_7.4 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Local version string: SSH-2.0-JSCH-0.1.52 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() CheckCiphers: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-ctr,arcfour,arcfour128,arcfour256 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() CheckKexes: diffie-hellman-group14-sha1,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() CheckSignatures: ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_KEXINIT sent 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_KEXINIT received 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,blowfish-cbc,cast128-cbc,3des-cbc 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,blowfish-cbc,cast128-cbc,3des-cbc 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: none,zlib@openssh.com 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: none,zlib@openssh.com 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: diffie-hellman-group1-sha1,diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha1,diffie-hellman-group-exchange-sha256,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: none 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: none 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server->client aes128-ctr hmac-sha1 none 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client->server aes128-ctr hmac-sha1 none 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_KEXDH_INIT sent 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() expecting SSH_MSG_KEXDH_REPLY 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() ssh_rsa_verify: signature true 22:21:49 WARNING [12] com.dom.util.logging.SimpleLoggerConfig log() Permanently added 'XXX' (RSA) to the list of known hosts. 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_NEWKEYS sent 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_NEWKEYS received 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_SERVICE_REQUEST sent 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_SERVICE_ACCEPT received 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Authentications that can continue: gssapi-with-mic,publickey,keyboard-interactive,password 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Next authentication method: gssapi-with-mic 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Authentications that can continue: publickey,keyboard-interactive,password 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Next authentication method: publickey 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Authentications that can continue: password 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Next authentication method: password 22:21:49 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Authentication succeeded (password). Saved results to myresults.xml

22:26:44 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Swingbench Version 2.6.0.1124 22:26:44 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Operating System: Linux 22:26:44 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Available processors (cores): 2 22:26:44 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Free memory (bytes): 498681208 22:26:44 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Maximum memory (bytes): 954728448 22:26:44 FINE [8] com.dom.benchmarking.swingbench.utilities.LogOSInfo logOSInfo() Total memory available to JVM (bytes): 514850816 22:26:44 FINE [8] com.dom.benchmarking.swingbench.CharBench parseConfig() Started CharBench 22:26:44 FINE [8] com.dom.benchmarking.swingbench.configuration.Configuration initConfiguration() Initialising configuration : Stress Test 22:26:44 FINE [8] com.dom.benchmarking.swingbench.configuration.Configuration initConfiguration() Overview 22:26:44 FINE [8] com.dom.benchmarking.swingbench.configuration.Configuration initConfiguration() Connection Refresh set to : 0 22:26:44 FINE [8] com.dom.benchmarking.swingbench.configuration.Configuration initConfiguration() Username = soe, Password = enc(cw4Xx9RgsQA=), Connectstring = jdbc:oracle:thin:@XXX:1521:oracl 22:26:44 FINE [8] com.dom.benchmarking.swingbench.frontend.CommandLineProcessor overrideConfig() Overriding config with command line parameters 22:26:44 FINE [8] com.dom.benchmarking.swingbench.frontend.CommandLineProcessor overrideConfig() Completed overrideConfig() 22:26:44 FINE [8] com.dom.benchmarking.swingbench.CharBench () Verbose outputfile : null Author : Dominic Giles Version : 2.6.0.1124

Results will be written to ./myresults.xml. 22:26:44 FINE [12] com.dom.benchmarking.swingbench.CharBench run() Beginning Run 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource () Level of statistics = simple 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource init() Initilization of swingbench datasource 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource init() Active Transaction = 4 22:26:44 FINE [12] com.dom.benchmarking.swingbench.CharBench run() Charbench starting in manual mode Hit Return to Terminate Run... 22:26:44 FINE [12] com.dom.benchmarking.swingbench.CharBench run() userSessionManager.start() invoked

Time Users TPM TPS

22:26:44 FINE [12] com.dom.benchmarking.swingbench.CharBench run() Entering main loop 22:26:44 FINE [12] com.dom.benchmarking.swingbench.CharBench run() StateChange 22:26:44 FINE [12] com.dom.benchmarking.swingbench.CharBench isRunning() isRunning returned true 22:26:44 FINE [12] com.dom.benchmarking.swingbench.CharBench run() State changed to running in run() 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSessionManager init() Initilization UserSessionManager() 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSessionManager initSessions() Initialising all of the sessions, creating 4 new sessions 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () STDebugging = false 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () STConnectionTolerance = 10000 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () MaximumTxRetries = -1 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () STRetriesInterval = 1000 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () STJitter = 0 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () maxInterDelay = 0 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () maxIntraDelay = 0 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () minInterDelay = 0 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () minIntraDelay = 0 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.UserSession () CommitClientSide = true 22:26:44 FINE [12] com.dom.benchmarking.swingbench.CharBench run() userSessionManager.init completed 22:26:44 FINE [12] com.dom.benchmarking.swingbench.CharBench run() listeners added 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource setStartedRun() Start of benchmark : setStartedRun() 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource setStartedRun() Attempting to connect with XXX 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource registerWithSystemMonitor() Attempting to register with System Monitor 22:26:44 FINE [12] com.dom.benchmarking.swingbench.kernel.SwingBenchDataSource registerWithSystemMonitor() Attempting to connect to SystemMonitor : oracle 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Connecting to suse-hyperv.swr.ard port 22 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Connection established 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Remote version string: SSH-2.0-OpenSSH_7.2 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Local version string: SSH-2.0-JSCH-0.1.52 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() CheckCiphers: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-ctr,arcfour,arcfour128,arcfour256 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() CheckKexes: diffie-hellman-group14-sha1,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() CheckSignatures: ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_KEXINIT sent 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_KEXINIT received 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ssh-dss,ecdsa-sha2-nistp256,ssh-ed25519 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: none,zlib@openssh.com 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: none,zlib@openssh.com 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server: 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: diffie-hellman-group1-sha1,diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha1,diffie-hellman-group-exchange-sha256,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: none 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: none 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client: 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: server->client aes128-ctr hmac-sha1 none 22:26:44 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() kex: client->server aes128-ctr hmac-sha1 none 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_KEXDH_INIT sent 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() expecting SSH_MSG_KEXDH_REPLY 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() ssh_rsa_verify: signature true 22:26:45 WARNING [12] com.dom.util.logging.SimpleLoggerConfig log() Permanently added 'XXX' (RSA) to the list of known hosts. 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_NEWKEYS sent 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_NEWKEYS received 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_SERVICE_REQUEST sent 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() SSH_MSG_SERVICE_ACCEPT received 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Authentications that can continue: publickey,keyboard-interactive,password 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Next authentication method: publickey 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Authentications that can continue: keyboard-interactive,password 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Next authentication method: keyboard-interactive 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Authentications that can continue: password 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Next authentication method: password 22:26:45 INFO [12] com.dom.util.logging.SimpleLoggerConfig log() Authentication succeeded (password). Saved results to myresults.xml 4287

./charbench -c ../configs/Stress_Test.xml -r ./myresults.xml -rt 00:01.00 -debug

<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<Results xmlns="http://www.dominicgiles.com/swingbench">
    <Overview>
        <BenchmarkName>Stress Test</BenchmarkName>
        <Comment>Simple relational CRUD workload test</Comment>
        <TimeOfRun>03.10.2020 22:21:49</TimeOfRun>
        <TotalRunTime>0:01:00</TotalRunTime>
        <TotalLogonTime>0:00:00</TotalLogonTime>
        <TotalCompletedTransactions>185017</TotalCompletedTransactions>
        <TotalFailedTransactions>0</TotalFailedTransactions>
        <AverageTransactionsPerSecond>3083.62</AverageTransactionsPerSecond>
        <MaximumTransactionRate>183716</MaximumTransactionRate>
    </Overview>
    <Configuration>
        <NumberOfUsers>1</NumberOfUsers>
        <MinimumInterThinkTime>0</MinimumInterThinkTime>
        <MaximumInterThinkTime>0</MaximumInterThinkTime>
        <MinimumIntraThinkTime>0</MinimumIntraThinkTime>
        <MaximumIntraThinkTime>0</MaximumIntraThinkTime>
        <ConnectString>XXX:1521:oracle</ConnectString>
        <TimingsIn>microseconds</TimingsIn>
        <WaitTillAllLogon>false</WaitTillAllLogon>
        <Driver>oracle.jdbc.pool.OracleDataSource</Driver>
    </Configuration>
    <DMLResults>
        <SelectStatements>77930</SelectStatements>
        <InsertStatements>29467</InsertStatements>
        <UpdateStatements>58342</UpdateStatements>
        <DeleteStatements>19278</DeleteStatements>
        <CommitStatements>107087</CommitStatements>
        <RollbackStatements>0</RollbackStatements>
    </DMLResults>
    <TransactionResults>
        <Result id="Insert Transaction">
            <AverageResponse>586.0352597821292</AverageResponse>
            <MinimumResponse>379</MinimumResponse>
            <MaximumResponse>71346</MaximumResponse>
            <TenthPrecentile>437</TenthPrecentile>
            <TwentiethPercentile>457</TwentiethPercentile>
            <ThirtiethPercentile>476</ThirtiethPercentile>
            <FortiethPrecentile>512</FortiethPrecentile>
            <FiftythPercentile>578</FiftythPercentile>
            <SixtiethPercentile>599</SixtiethPercentile>
            <SeventiethPercentile>615</SeventiethPercentile>
            <EightiethPercentile>630</EightiethPercentile>
            <NinetiethPercentile>650</NinetiethPercentile>
            <TransactionCount>29467</TransactionCount>
            <FailedTransactionCount>0</FailedTransactionCount>
            <RollbackCount>0</RollbackCount>
        </Result>
        <Result id="Simple Select">
            <AverageResponse>155.3125497241114</AverageResponse>
            <MinimumResponse>135</MinimumResponse>
            <MaximumResponse>53304</MaximumResponse>
            <TenthPrecentile>140</TenthPrecentile>
            <TwentiethPercentile>141</TwentiethPercentile>
            <ThirtiethPercentile>143</ThirtiethPercentile>
            <FortiethPrecentile>145</FortiethPrecentile>
            <FiftythPercentile>146</FiftythPercentile>
            <SixtiethPercentile>149</SixtiethPercentile>
            <SeventiethPercentile>151</SeventiethPercentile>
            <EightiethPercentile>155</EightiethPercentile>
            <NinetiethPercentile>161</NinetiethPercentile>
            <TransactionCount>77930</TransactionCount>
            <FailedTransactionCount>0</FailedTransactionCount>
            <RollbackCount>0</RollbackCount>
        </Result>
        <Result id="Update Transaction">
            <AverageResponse>333.50649617771074</AverageResponse>
            <MinimumResponse>176</MinimumResponse>
            <MaximumResponse>19882</MaximumResponse>
            <TenthPrecentile>190</TenthPrecentile>
            <TwentiethPercentile>190</TwentiethPercentile>
            <ThirtiethPercentile>190</ThirtiethPercentile>
            <FortiethPrecentile>352</FortiethPrecentile>
            <FiftythPercentile>364</FiftythPercentile>
            <SixtiethPercentile>376</SixtiethPercentile>
            <SeventiethPercentile>388</SeventiethPercentile>
            <EightiethPercentile>401</EightiethPercentile>
            <NinetiethPercentile>417</NinetiethPercentile>
            <TransactionCount>58342</TransactionCount>
            <FailedTransactionCount>0</FailedTransactionCount>
            <RollbackCount>0</RollbackCount>
        </Result>
        <Result id="Delete Transaction">
            <AverageResponse>435.0501608050628</AverageResponse>
            <MinimumResponse>178</MinimumResponse>
            <MaximumResponse>18330</MaximumResponse>
            <TenthPrecentile>185</TenthPrecentile>
            <TwentiethPercentile>185</TwentiethPercentile>
            <ThirtiethPercentile>191</ThirtiethPercentile>
            <FortiethPrecentile>498</FortiethPrecentile>
            <FiftythPercentile>543</FiftythPercentile>
            <SixtiethPercentile>554</SixtiethPercentile>
            <SeventiethPercentile>565</SeventiethPercentile>
            <EightiethPercentile>577</EightiethPercentile>
            <NinetiethPercentile>597</NinetiethPercentile>
            <TransactionCount>19278</TransactionCount>
            <FailedTransactionCount>0</FailedTransactionCount>
            <RollbackCount>0</RollbackCount>
        </Result>
    </TransactionResults>
    <BenchmarkMetrics>
        <TPSReadings>1601756510183, 0,1601756511183, 1481,1601756512184, 2463,1601756513185, 2653,1601756514186, 2753,1601756515186, 2930,1601756516187, 3001,1601756517187, 2926,1601756518187, 3056,1601756519188, 3059,1601756520188, 2971,1601756521188, 2954,1601756522188, 2876,1601756523188, 3188,1601756524189, 3064,1601756525189, 2935,1601756526189, 3085,1601756527189, 3040,1601756528189, 3228,1601756529190, 3204,1601756530190, 3171,1601756531190, 3158,1601756532190, 3136,1601756533190, 3213,1601756534191, 3259,1601756535192, 3235,1601756536192, 3305,1601756537192, 3168,1601756538192, 3218,1601756539193, 3267,1601756540193, 3298,1601756541193, 3292,1601756542193, 3229,1601756543193, 3217,1601756544194, 3164,1601756545194, 3209,1601756546194, 3171,1601756547194, 3220,1601756548194, 3249,1601756549195, 3204,1601756550195, 3152,1601756551195, 3268,1601756552195, 3243,1601756553195, 3280,1601756554196, 3140,1601756555196, 3225,1601756556196, 3209,1601756557196, 3234,1601756558196, 3231,1601756559197, 3214,1601756560197, 2990,1601756561197, 3193,1601756562197, 3281,1601756563197, 3323,1601756564197, 3253,1601756565198, 3166,1601756566198, 3274,1601756567198, 3221,1601756568198, 3267,1601756569198, 3301,</TPSReadings>
    </BenchmarkMetrics>
</Results>

./charbench -c ../configs/Stress_Test.xml -r ./myresults.xml

<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<Results xmlns="http://www.dominicgiles.com/swingbench">
    <Overview>
        <BenchmarkName>Stress Test</BenchmarkName>
        <Comment>Simple relational CRUD workload test</Comment>
        <TimeOfRun>03.10.2020 22:40:27</TimeOfRun>
        <TotalRunTime>0:01:01</TotalRunTime>
        <TotalLogonTime>0:00:00</TotalLogonTime>
        <TotalCompletedTransactions>186725</TotalCompletedTransactions>
        <TotalFailedTransactions>0</TotalFailedTransactions>
        <AverageTransactionsPerSecond>3061.07</AverageTransactionsPerSecond>
        <MaximumTransactionRate>185484</MaximumTransactionRate>
        <AverageUsrCPU>33</AverageUsrCPU>
        <AverageSysCPU>11</AverageSysCPU>
        <AverageWaitCPU>9</AverageWaitCPU>
    </Overview>
    <Configuration>
        <NumberOfUsers>1</NumberOfUsers>
        <MinimumInterThinkTime>0</MinimumInterThinkTime>
        <MaximumInterThinkTime>0</MaximumInterThinkTime>
        <MinimumIntraThinkTime>0</MinimumIntraThinkTime>
        <MaximumIntraThinkTime>0</MaximumIntraThinkTime>
        <ConnectString>XXX:1521:oracle</ConnectString>
        <TimingsIn>microseconds</TimingsIn>
        <WaitTillAllLogon>false</WaitTillAllLogon>
        <Driver>oracle.jdbc.pool.OracleDataSource</Driver>
    </Configuration>
    <DMLResults>
        <SelectStatements>78533</SelectStatements>
        <InsertStatements>29605</InsertStatements>
        <UpdateStatements>59014</UpdateStatements>
        <DeleteStatements>19573</DeleteStatements>
        <CommitStatements>108192</CommitStatements>
        <RollbackStatements>0</RollbackStatements>
    </DMLResults>
    <TransactionResults>
        <Result id="Insert Transaction">
            <AverageResponse>594.9653099138659</AverageResponse>
            <MinimumResponse>380</MinimumResponse>
            <MaximumResponse>51865</MaximumResponse>
            <TenthPrecentile>444</TenthPrecentile>
            <TwentiethPercentile>460</TwentiethPercentile>
            <ThirtiethPercentile>480</ThirtiethPercentile>
            <FortiethPrecentile>532</FortiethPrecentile>
            <FiftythPercentile>574</FiftythPercentile>
            <SixtiethPercentile>600</SixtiethPercentile>
            <SeventiethPercentile>620</SeventiethPercentile>
            <EightiethPercentile>637</EightiethPercentile>
            <NinetiethPercentile>659</NinetiethPercentile>
            <TransactionCount>29605</TransactionCount>
            <FailedTransactionCount>0</FailedTransactionCount>
            <RollbackCount>0</RollbackCount>
        </Result>
        <Result id="Simple Select">
            <AverageResponse>155.63789744438643</AverageResponse>
            <MinimumResponse>134</MinimumResponse>
            <MaximumResponse>52043</MaximumResponse>
            <TenthPrecentile>140</TenthPrecentile>
            <TwentiethPercentile>141</TwentiethPercentile>
            <ThirtiethPercentile>143</ThirtiethPercentile>
            <FortiethPrecentile>145</FortiethPrecentile>
            <FiftythPercentile>147</FiftythPercentile>
            <SixtiethPercentile>149</SixtiethPercentile>
            <SeventiethPercentile>151</SeventiethPercentile>
            <EightiethPercentile>156</EightiethPercentile>
            <NinetiethPercentile>164</NinetiethPercentile>
            <TransactionCount>78533</TransactionCount>
            <FailedTransactionCount>0</FailedTransactionCount>
            <RollbackCount>0</RollbackCount>
        </Result>
        <Result id="Update Transaction">
            <AverageResponse>336.23629986104993</AverageResponse>
            <MinimumResponse>177</MinimumResponse>
            <MaximumResponse>39221</MaximumResponse>
            <TenthPrecentile>192</TenthPrecentile>
            <TwentiethPercentile>192</TwentiethPercentile>
            <ThirtiethPercentile>192</ThirtiethPercentile>
            <FortiethPrecentile>329</FortiethPrecentile>
            <FiftythPercentile>372</FiftythPercentile>
            <SixtiethPercentile>387</SixtiethPercentile>
            <SeventiethPercentile>400</SeventiethPercentile>
            <EightiethPercentile>410</EightiethPercentile>
            <NinetiethPercentile>427</NinetiethPercentile>
            <TransactionCount>59014</TransactionCount>
            <FailedTransactionCount>0</FailedTransactionCount>
            <RollbackCount>0</RollbackCount>
        </Result>
        <Result id="Delete Transaction">
            <AverageResponse>435.29985183671386</AverageResponse>
            <MinimumResponse>175</MinimumResponse>
            <MaximumResponse>18315</MaximumResponse>
            <TenthPrecentile>185</TenthPrecentile>
            <TwentiethPercentile>185</TwentiethPercentile>
            <ThirtiethPercentile>192</ThirtiethPercentile>
            <FortiethPrecentile>403</FortiethPrecentile>
            <FiftythPercentile>542</FiftythPercentile>
            <SixtiethPercentile>557</SixtiethPercentile>
            <SeventiethPercentile>572</SeventiethPercentile>
            <EightiethPercentile>582</EightiethPercentile>
            <NinetiethPercentile>604</NinetiethPercentile>
            <TransactionCount>19573</TransactionCount>
            <FailedTransactionCount>0</FailedTransactionCount>
            <RollbackCount>0</RollbackCount>
        </Result>
    </TransactionResults>
    <BenchmarkMetrics>
        <TPSReadings>1601757628494, 0,1601757629495, 1383,1601757630495, 2424,1601757631495, 2647,1601757632495, 2771,1601757633496, 2915,1601757634496, 2898,1601757635496, 3101,1601757636496, 3195,1601757637497, 3207,1601757638497, 3144,1601757639497, 3005,1601757640497, 2920,1601757641498, 3244,1601757642498, 3247,1601757643498, 3214,1601757644498, 3179,1601757645499, 3189,1601757646499, 3218,1601757647499, 3221,1601757648499, 3282,1601757649499, 3034,1601757650500, 2955,1601757651500, 2872,1601757652500, 2998,1601757653500, 3270,1601757654500, 3299,1601757655500, 3110,1601757656501, 3157,1601757657501, 3273,1601757658501, 3321,1601757659501, 3325,1601757660502, 3156,1601757661502, 3207,1601757662502, 3136,1601757663502, 3095,1601757664502, 3163,1601757665503, 3135,1601757666503, 3070,1601757667503, 3204,1601757668503, 3116,1601757669504, 3132,1601757670504, 3151,1601757671504, 3085,1601757672504, 3240,1601757673504, 3189,1601757674505, 3159,1601757675505, 3075,1601757676505, 3115,1601757677505, 3151,1601757678506, 3129,1601757679506, 3153,1601757680506, 3071,1601757681506, 3051,1601757682507, 3306,1601757683507, 3227,1601757684507, 3246,1601757685507, 3108,1601757686508, 3209,1601757687508, 3211,1601757688508, 3176,</TPSReadings>
        <CPUReadings>1601757627877, 0, 0, 0, 1601757629111, 68, 7, 4, 1601757630112, 71, 10, 4, 1601757631113, 63, 13, 4, 1601757632113, 56, 12, 8, 1601757633114, 44, 11, 8, 1601757634115, 47, 11, 8, 1601757635114, 38, 12, 12, 1601757636114, 34, 12, 9, 1601757637114, 32, 12, 8, 1601757638115, 30, 10, 10, 1601757639115, 28, 14, 10, 1601757640115, 26, 15, 11, 1601757641116, 47, 12, 11, 1601757642116, 78, 12, 7, 1601757643117, 29, 12, 10, 1601757644117, 31, 12, 9, 1601757645116, 30, 11, 10, 1601757646117, 35, 11, 10, 1601757647117, 30, 11, 9, 1601757648117, 30, 11, 9, 1601757649117, 31, 11, 10, 1601757650117, 28, 10, 12, 1601757651118, 27, 12, 12, 1601757652118, 27, 11, 12, 1601757653118, 29, 13, 10, 1601757654118, 31, 12, 9, 1601757655118, 29, 12, 10, 1601757656119, 30, 11, 9, 1601757657119, 31, 13, 8, 1601757658119, 30, 13, 8, 1601757659119, 31, 13, 7, 1601757660119, 30, 12, 9, 1601757661119, 32, 11, 9, 1601757662120, 31, 11, 9, 1601757663120, 30, 11, 11, 1601757664120, 29, 12, 11, 1601757665120, 31, 10, 11, 1601757666121, 28, 12, 12, 1601757667121, 30, 12, 11, 1601757668121, 31, 10, 11, 1601757669122, 30, 12, 11, 1601757670122, 30, 10, 11, 1601757671122, 31, 11, 11, 1601757672122, 30, 12, 10, 1601757673123, 30, 13, 9, 1601757674123, 30, 11, 11, 1601757675123, 29, 11, 11, 1601757676123, 29, 12, 12, 1601757677123, 30, 11, 11, 1601757678124, 30, 11, 10, 1601757679124, 30, 11, 12, 1601757680124, 29, 12, 12, 1601757681124, 29, 12, 11, 1601757682125, 31, 11, 11, 1601757683125, 29, 13, 10, 1601757684125, 30, 12, 10, 1601757685125, 28, 13, 11, 1601757686125, 30, 12, 11, 1601757687126, 30, 12, 10, 1601757688126, 29, 13, 10, </CPUReadings>
        <IOReadings>1601757627877, 0, 0, 1601757629111, 0, 15244, 1601757630112, 0, 6188, 1601757631113, 0, 6880, 1601757632113, 0, 7672, 1601757633114, 0, 7796, 1601757634115, 0, 8120, 1601757635114, 0, 7692, 1601757636114, 0, 8364, 1601757637114, 0, 8380, 1601757638115, 0, 8204, 1601757639115, 0, 8040, 1601757640115, 0, 8040, 1601757641116, 0, 8052, 1601757642116, 0, 8836, 1601757643117, 0, 8756, 1601757644117, 0, 8584, 1601757645116, 0, 8500, 1601757646117, 0, 8468, 1601757647117, 0, 8612, 1601757648117, 0, 8652, 1601757649117, 0, 8724, 1601757650117, 0, 10880, 1601757651118, 0, 10508, 1601757652118, 0, 10260, 1601757653118, 0, 8644, 1601757654118, 0, 8736, 1601757655118, 0, 8568, 1601757656119, 0, 8780, 1601757657119, 0, 8724, 1601757658119, 0, 9064, 1601757659119, 0, 8764, 1601757660119, 0, 8608, 1601757661119, 0, 8712, 1601757662120, 0, 8524, 1601757663120, 0, 8748, 1601757664120, 0, 8508, 1601757665120, 0, 8556, 1601757666121, 0, 8344, 1601757667121, 0, 8300, 1601757668121, 0, 8520, 1601757669122, 0, 8356, 1601757670122, 0, 8800, 1601757671122, 0, 8600, 1601757672122, 0, 8568, 1601757673123, 0, 8764, 1601757674123, 0, 8428, 1601757675123, 0, 8372, 1601757676123, 0, 8308, 1601757677123, 0, 8452, 1601757678124, 0, 8584, 1601757679124, 0, 8396, 1601757680124, 0, 8564, 1601757681124, 0, 8616, 1601757682125, 0, 8120, 1601757683125, 0, 8576, 1601757684125, 0, 8584, 1601757685125, 0, 8376, 1601757686125, 0, 8616, 1601757687126, 0, 8584, 1601757688126, 0, 8676, </IOReadings>
    </BenchmarkMetrics>
</Results>
domgiles commented 2 years ago

Looks like a bug. I'll try and get a fix.