|
The Second stress test involves, Pass 6 millions of records from a Flat File, to a table in MySQL. |
|
As in most of the Test, there are several cases using differents techniques, setting of variables, with the same objective, satisfy the requirement and improve the performance. Always the first case is the best, and the rest of cases, are jobs that don't have the most appropiate set up options, but helped in the way to reach the goal of improving performance.
|
LINKS
|
|
CASE 1: MySQL in other VM + -server + Xmx=1500 + 100K CommitSize
| Objective: | To measure elapsed time reading and writing 6 million rows, from Flat file, to a MySQL database. In this case (case 1), the database run in the same virtual machine, therefore, Clover & DB share the disk (key point), but the MySQL Service consume CPU. |
| Rows: | 6.024.000 M |
| Columns: | 37 Columns |
| Resources: | Virtual machine with: 2 GB RAM, Clover & MySQL like main process over the virtual plataform. The resources used are anecdotal, today, Any production environment has enough processing power for current and future requirements. The objective here, is to build, to execute and to measure with the same environment (regardless of the limited resources) |
| Structure: |  |
| Design & Run |  |
| Elapsed time (s) | 3882 sec. |
| How to Improve Perform. |
- Change Commit Size to 100.000 r/ (for this case) - Use ServerMode - Change -Xmx to 1.500MB |
| Summary of log | INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 08/03/12 13:54:50 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.05 Out:0 5967619 1515374 1861 467 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.14 In:0 5967619 1515374 1861 467 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 08/03/12 13:54:55 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.05 Out:0 5974024 1516984 1272 319 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.14 In:0 5974024 1516984 1272 319 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 08/03/12 13:55:00 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.05 Out:0 5982780 1519183 1728 434 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.14 In:0 5982780 1519183 1728 434 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 08/03/12 13:55:05 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.05 Out:0 5988841 1520706 1204 302 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.14 In:0 5988841 1520706 1204 302 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 08/03/12 13:55:10 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.05 Out:0 5995917 1522483 1410 354 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.14 In:0 5995917 1522483 1410 354 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 08/03/12 13:55:15 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.05 Out:0 6003674 1524430 1518 381 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.14 In:0 6003674 1524430 1518 381 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 08/03/12 13:55:20 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.05 Out:0 6015137 1527307 2288 574 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.14 In:0 6015137 1527307 2288 574 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 08/03/12 13:55:25 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.05 Out:0 6022839 1529241 1534 385 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.14 In:0 6022839 1529241 1534 385 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - [Clover] Post-execute phase finalization: 0 INFO [WatchDog] - [Clover] phase: 0 post-execute finalization successfully. INFO [WatchDog] - ----------------------** Final tracking Log for phase [0] **--------------------- INFO [WatchDog] - Time: 08/03/12 13:55:29 INFO [WatchDog] - Node ID Port #Records #KB aRec/s aKB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 FINISHED_OK INFO [WatchDog] - %cpu:0.05 Out:0 6029426 1530895 1553 394 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 FINISHED_OK INFO [WatchDog] - %cpu:0.21 In:0 6029426 1530895 1553 394 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - Execution of phase [0] successfully finished - elapsed time(sec): 3881 INFO [WatchDog] - Post-execute finalization of connection: INFO [WatchDog] - DBConnection driver[org.jetel.connection.jdbc.driver.JdbcDriver@6b93c5]:jndi[null]:url[jdbc:mysql://192.168.0.114:3306/world]:user[root] ... OK INFO [WatchDog] - -----------------------** Summary of Phases execution **--------------------- INFO [WatchDog] - Phase# Finished Status RunTime(sec) MemoryAllocation(KB) INFO [WatchDog] - 0 FINISHED_OK 3881 15791 INFO [WatchDog] - ------------------------------** End of Summary **--------------------------- INFO [WatchDog] - WatchDog thread finished - total execution time: 3882 (sec) INFO [main] - Freeing graph resources. INFO [main] - Execution of graph successful ! |
CASE 2: MySQL in the Same VM (excepcional case) + without -server + Xmx=0
| Objective: | To measure elapsed time reading and writing 6 million rows, from Flat file, to a MySQL database. In this case (case 1), the database runs in the same virtual machine, therefore, Clover & DB share the disk (key point), but the MySQL Service consume CPU. |
| Rows: | 6.024.000 M |
| Columns: | 37 Columns |
| Resources: | Virtual machine with: 2 GB RAM, Clover & MySQL like main process over the virtual plataform. The resources used are anecdotal, today, Any production environment has enough processing power for current and future requirements. The objective here, is to build, to execute and to measure with the same environment (regardless of the limited resources) |
| Structure: | |
| Design & Run |  |
| Elapsed time (s) | 4647 sec. |
| Rows per sec (avg) |
Here, show the evolution of the passage of rows via the transformations, each 5 seconds.
1.469 rows/sec
|
| % cpu |
Node reader: 0,04 % a 0,05% Node writer: 0,21% a 0,22%
|
| Summary of log | INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 22/02/12 19:04:30 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.04 Out:0 5984798 1519690 2250 565 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.21 In:0 5984798 1519690 2250 565 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 22/02/12 19:04:35 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.04 Out:0 5996926 1522737 2400 602 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.21 In:0 5996926 1522737 2400 602 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 22/02/12 19:04:40 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.04 Out:0 6007045 1525276 2014 505 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.21 In:0 6007045 1525276 2014 505 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 22/02/12 19:04:45 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.04 Out:0 6018173 1528069 2189 549 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.21 In:0 6018173 1528069 2189 549 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 22/02/12 19:04:50 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.04 Out:0 6024239 1529592 1203 302 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.21 In:0 6024239 1529592 1203 302 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - [Clover] Post-execute phase finalization: 0 INFO [WatchDog] - [Clover] phase: 0 post-execute finalization successfully. INFO [WatchDog] - ----------------------** Final tracking Log for phase [0] **--------------------- INFO [WatchDog] - Time: 22/02/12 19:04:53 INFO [WatchDog] - Node ID Port #Records #KB aRec/s aKB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 FINISHED_OK INFO [WatchDog] - %cpu:0.05 Out:0 6029426 1530895 1298 329 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 FINISHED_OK INFO [WatchDog] - %cpu:0.22 In:0 6029426 1530895 1298 329 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - Execution of phase [0] successfully finished - elapsed time(sec): 4642 INFO [WatchDog] - Post-execute finalization of connection: INFO [WatchDog] - DBConnection driver[org.jetel.connection.jdbc.driver.JdbcDriver@156b386]:jndi[null]:url[jdbc:mysql://localhost:3306/world]:user[root] ... OK INFO [WatchDog] - -----------------------** Summary of Phases execution **--------------------- INFO [WatchDog] - Phase# Finished Status RunTime(sec) MemoryAllocation(KB) INFO [WatchDog] - 0 FINISHED_OK 4642 11024 INFO [WatchDog] - ------------------------------** End of Summary **--------------------------- INFO [WatchDog] - WatchDog thread finished - total execution time: 4647 (sec) INFO [main] - Freeing graph resources. INFO [main] - Execution of graph successful ! |
CASE 3: MySQL in the other VM + without -server + Xmx=0
| Objective: | To measure elapsed time reading and writing 6 million rows, from Flat file, to a MySQL database. In this case (case 2), the database run in other machine. The benefit es "Clear", only Clover run alone in the virtual machine. The negative point is the transfer of data through the network, using the generic drivers installed by VM. |
| Rows: | 6.024.000 M |
| Columns: | 37 Columns |
| Resources: | Virtual machine with: 2 GB RAM, Clover like main process over the virtual plataform. The resources used are anecdotal, today, Any production environment has enough processing power for current and future requirements. The objective here, is use and to measure with the same environment (regardless of the limited resources) |
| Structure: | |
| Design & Run | |
| Elapsed time (s) | 6808 sec. |
| Rows per sec (avg) |
Here, show the evolution of the passage of rows via the transformations, each 5 seconds.
958 rows/sec
|
| % cpu |
Node reader: 0,03 % a 0,04% Node writer: 0,04% a 0,06%
|
| Summary of log | INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.03 Out:0 5998952 1523245 1153 289 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.04 In:0 5998952 1523245 1153 289 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 23/02/12 11:58:11 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.03 Out:0 6004007 1524514 1007 253 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.04 In:0 6004007 1524514 1007 253 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 23/02/12 11:58:16 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.03 Out:0 6008055 1525530 806 202 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.04 In:0 6008055 1525530 806 202 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 23/02/12 11:58:21 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.03 Out:0 6012103 1526545 806 202 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.04 In:0 6012103 1526545 806 202 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 23/02/12 11:58:26 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.03 Out:0 6017160 1527815 1008 253 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.04 In:0 6017160 1527815 1008 253 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 23/02/12 11:58:31 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.03 Out:0 6022218 1529085 1008 253 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.04 In:0 6022218 1529085 1008 253 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **------------------- INFO [WatchDog] - Time: 23/02/12 11:58:36 INFO [WatchDog] - Node ID Port #Records #KB Rec/s KB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 RUNNING INFO [WatchDog] - %cpu:0.03 Out:0 6027271 1530354 1007 253 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 RUNNING INFO [WatchDog] - %cpu:0.04 In:0 6027271 1530354 1007 253 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - [Clover] Post-execute phase finalization: 0 INFO [WatchDog] - [Clover] phase: 0 post-execute finalization successfully. INFO [WatchDog] - ----------------------** Final tracking Log for phase [0] **--------------------- INFO [WatchDog] - Time: 23/02/12 11:58:41 INFO [WatchDog] - Node ID Port #Records #KB aRec/s aKB/s INFO [WatchDog] - --------------------------------------------------------------------------------- INFO [WatchDog] - UniversalDataReader DATA_READER0 FINISHED_OK INFO [WatchDog] - %cpu:0.04 Out:0 6029426 1530895 885 224 INFO [WatchDog] - DBOutputTable DB_OUTPUT_TABLE0 FINISHED_OK INFO [WatchDog] - %cpu:0.06 In:0 6029426 1530895 885 224 INFO [WatchDog] - ---------------------------------** End of Log **-------------------------------- INFO [WatchDog] - Execution of phase [0] successfully finished - elapsed time(sec): 6808 INFO [WatchDog] - Post-execute finalization of connection: INFO [WatchDog] - DBConnection driver[org.jetel.connection.jdbc.driver.JdbcDriver@95215b]:jndi[null]:url[jdbc:mysql://192.168.0.109:3306/world]:user[root] ... OK INFO [WatchDog] - -----------------------** Summary of Phases execution **--------------------- INFO [WatchDog] - Phase# Finished Status RunTime(sec) MemoryAllocation(KB) INFO [WatchDog] - 0 FINISHED_OK 6808 12148 INFO [WatchDog] - ------------------------------** End of Summary **--------------------------- INFO [WatchDog] - WatchDog thread finished - total execution time: 6808 (sec) INFO [main] - Freeing graph resources. INFO [main] - Execution of graph successful ! |
