sormula | simple (easy) object relational mapping | |
|
Database database = new Database(connection, getSchema()); database.setTimings(true); // enable timings for all operations do some database activity... database.logTimings(); // log all timings Thu 17:48:14 INFO [main] org.sormula.Database - logTimings: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - logTimings: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - timingId =BECA8350 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - description=All uses of SELECT id, type, description FROM SormulaTest4 WHERE id = ? Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - prepare = 77% 00:00:00.003340523 n= 21 avg=00:00:00.000159073 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - write = 2% 00:00:00.000102102 n= 21 avg=00:00:00.000004862 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - execute = 11% 00:00:00.000467966 n= 21 avg=00:00:00.000022284 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - read = 10% 00:00:00.000445421 n= 21 avg=00:00:00.000021211 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - total =100% 00:00:00.004356012 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - initiated from: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveNew1(SaveTest.java:90) n=1 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveCollection(SaveTest.java:126) n=19 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveExisting1(SaveTest.java:68) n=1 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - logTimings: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - timingId =C546A50B Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - description=All uses of UPDATE SormulaTest4 SET id=?, type=?, description=? WHERE id = ? Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - prepare = 7% 00:00:00.000561817 n= 3 avg=00:00:00.000187272 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - write = 5% 00:00:00.000387420 n= 21 avg=00:00:00.000018449 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - execute = 88% 00:00:00.006889139 n= 21 avg=00:00:00.000328054 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - read = 0% 00:00:00.000000000 n= 0 avg=00:00:00.000000000 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - total =100% 00:00:00.007838376 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - initiated from: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveCollection(SaveTest.java:121) n=19 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveNew1(SaveTest.java:87) n=1 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveExisting1(SaveTest.java:65) n=1 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - logTimings: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - timingId =C63B7AE0 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - description=All uses of SELECT id, type, description FROM SormulaTest4 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - prepare = 19% 00:00:00.001023828 n= 2 avg=00:00:00.000511914 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - write = 0% 00:00:00.000006068 n= 2 avg=00:00:00.000003034 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - execute = 3% 00:00:00.000160520 n= 2 avg=00:00:00.000080260 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - read = 78% 00:00:00.004166603 n=191 avg=00:00:00.000021815 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - total =100% 00:00:00.005357019 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - initiated from: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.DatabaseTest.selectTestRows(DatabaseTest.java:238) n=2 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - logTimings: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - timingId =CFC3F90A Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - description=All uses of INSERT INTO SormulaTest4(id, type, description) VALUES (?, ?, ?) Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - prepare = 34% 00:00:00.000340531 n= 2 avg=00:00:00.000170266 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - write = 12% 00:00:00.000121937 n= 10 avg=00:00:00.000012194 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - execute = 54% 00:00:00.000543775 n= 10 avg=00:00:00.000054378 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - read = 0% 00:00:00.000000000 n= 0 avg=00:00:00.000000000 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - total =100% 00:00:00.001006243 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - initiated from: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveCollection(SaveTest.java:121) n=9 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveNew1(SaveTest.java:87) n=1 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - logTimings: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - timingId =Database totals Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - description=All operations for database Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - prepare = 28% 00:00:00.005266699 n= 28 avg=00:00:00.000188096 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - write = 3% 00:00:00.000617527 n= 54 avg=00:00:00.000011436 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - execute = 43% 00:00:00.008061400 n= 54 avg=00:00:00.000149285 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - read = 25% 00:00:00.004612024 n=212 avg=00:00:00.000021755 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - total =100% 00:00:00.018557650 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - initiated from: Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveCollection(SaveTest.java:121) n=28 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveNew1(SaveTest.java:87) n=2 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveNew1(SaveTest.java:90) n=1 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveExisting1(SaveTest.java:65) n=1 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveCollection(SaveTest.java:126) n=19 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.operation.SaveTest.saveExisting1(SaveTest.java:68) n=1 Thu 17:48:14 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.tests.DatabaseTest.selectTestRows(DatabaseTest.java:238) n=2 Performance recording and logging can also be performed for one operation through
SqlOperation#setTimings
and SqlOperation#logTimings.
ArrayList Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - logTimings: Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - timingId =38567C0C Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - description=SELECT id, firstName, lastName, graduationDate FROM Student WHERE id IN (?, ?) Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - prepare = 50% 00:00:00.000382423 n= 1 avg=00:00:00.000382423 Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - write = 7% 00:00:00.000054496 n= 1 avg=00:00:00.000054496 Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - execute = 25% 00:00:00.000190143 n= 1 avg=00:00:00.000190143 Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - read = 19% 00:00:00.000144009 n= 2 avg=00:00:00.000072005 Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - total =100% 00:00:00.000771071 Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - initiated from: Thu 17:39:30 INFO [main] org.sormula.operation.monitor.OperationTime - org.sormula.examples.basic.BasicSelect.selectIn(BasicSelect.java:109) n=1 |
|
© 2018 Sormula, LLC |