測試背景
最近公司接到一個新客戶關係管理項目,爲了可以提升開發效率,研發經理嘗試了不少種方法,終於在一個Spdycoding(https://www.spdycoding.com/)的網站上找到了能夠快速自動生成代碼的delicacy生成器,讓我研究研究帶領小團隊學習使用。前端
delicacy框架是一個基礎MVC架構的後臺框架,提供標準的接口訪問,裏面封裝了DelicacyDao(數據庫持久層),無需再使用第三的數據庫持久層框架,官網提供delicacy代碼生成器,結合delicacy框架,能夠經過數據庫定義的表結構、自定義寫的複雜SQL語句生成相應數據庫操做代碼(增、刪、改、查),同時能夠根據用戶的需求生成相對應的前端頁面代碼。web
拿到生成器和jar包,我先看了反編出來的代碼,瞭解開發者的邏輯思惟。這是一個與經常使用spring項目不一樣的思惟,delicacy生成後的代碼與jar包中的基礎類契合,構成了以servlet爲基礎的web項目。萬變不離其宗,以servlet爲基礎則離不開接口業務分發,delicay使用了單一接口地址,按約定參數分發業務的方式。同時使用了內置按線程綁定的數據庫鏈接池,更使人驚訝的是,統一了對象的tojson方法,各對象重寫此方法實現本身的行爲多態,着實驚豔!更多細節有品味之處便不在這裏一一講述。spring
驚豔事後,我開始探究此結構的便利性與執行性能,並試圖與springmvc+mybatis項目做對比,那麼第一步是構建項目。最典型的servlet項目pom、ant等打包,war部署,delicacy的項目一樣如此,只要三個簡單的配置——web.xml、數據源與log4j日誌,項目就能夠啓動了(此處有坑,先賣關子)。固然因爲這次是測試性質,咱們在項目裏寫了不少程序起點的main()用來測試單獨的一個方面,也把war放入tomcat測試了應用性能。好了,閒言到此爲此,請看如下測試數據。sql
測試項目及簡析單表插入數據庫
delicacy第一次json
單次循環插入tomcat
2019-12-07 01:14:32 [TestMain]-[WARN] 插入100條數據使用時間是:206mybatis
2019-12-07 01:14:33 [TestMain]-[WARN] 插入1000條數據使用時間是:1588多線程
2019-12-07 01:14:47 [TestMain]-[WARN] 插入10000條數據使用時間是:14073架構
批量插入
2019-12-07 01:14:48 [TestMain]-[WARN] 插入100條數據使用時間是:168
2019-12-07 01:14:49 [TestMain]-[WARN] 插入1000條數據使用時間是:1389
2019-12-07 01:15:03 [TestMain]-[WARN] 插入10000條數據使用時間是:13736
delicacy第二次
單次循環插入
2019-12-07 01:19:16 [TestMain]-[WARN] 插入100條數據使用時間是:201
2019-12-07 01:19:18 [TestMain]-[WARN] 插入1000條數據使用時間是:1508
2019-12-07 01:19:32 [TestMain]-[WARN] 插入10000條數據使用時間是:14254
批量插入
2019-12-07 01:19:32 [TestMain]-[WARN] 插入100條數據使用時間是:169
2019-12-07 01:19:33 [TestMain]-[WARN] 插入1000條數據使用時間是:1394
2019-12-07 01:19:47 [TestMain]-[WARN] 插入10000條數據使用時間是:13840
delicacy第三次
單次循環插入
2019-12-07 01:22:00 [TestMain]-[WARN] 插入100條數據使用時間是:196
2019-12-07 01:22:02 [TestMain]-[WARN] 插入1000條數據使用時間是:1509
2019-12-07 01:22:16 [TestMain]-[WARN] 插入10000條數據使用時間是:14261
批量插入
2019-12-07 01:22:16 [TestMain]-[WARN] 插入100條數據使用時間是:168
2019-12-07 01:22:17 [TestMain]-[WARN] 插入1000條數據使用時間是:1390
2019-12-07 01:22:31 [TestMain]-[WARN] 插入10000條數據使用時間是:13723
mybatis第一次
單次循環插入
2019-12-07 01:16:24 [TestMain]-[WARN] 插入100條數據使用時間是:488
2019-12-07 01:16:26 [TestMain]-[WARN] 插入1000條數據使用時間是:1602
2019-12-07 01:16:41 [TestMain]-[WARN] 插入10000條數據使用時間是:15536
批量插入
2019-12-07 01:16:42 [TestMain]-[WARN] 插入100條數據使用時間是:87
2019-12-07 01:16:42 [TestMain]-[WARN] 插入1000條數據使用時間是:121
2019-12-07 01:16:42 [TestMain]-[WARN] 插入10000條數據使用時間是:507
mybatis第二次
單次循環插入
2019-12-07 01:20:33 [TestMain]-[WARN] 插入100條數據使用時間是:480
2019-12-07 01:20:34 [TestMain]-[WARN] 插入1000條數據使用時間是:1618
2019-12-07 01:20:50 [TestMain]-[WARN] 插入10000條數據使用時間是:15252
批量插入
2019-12-07 01:20:50 [TestMain]-[WARN] 插入100條數據使用時間是:89
2019-12-07 01:20:50 [TestMain]-[WARN] 插入1000條數據使用時間是:116
2019-12-07 01:20:50 [TestMain]-[WARN] 插入10000條數據使用時間是:505
mybatis第三次
單次循環
2019-12-07 01:23:51 [TestMain]-[WARN] 插入100條數據使用時間是:469
2019-12-07 01:23:53 [TestMain]-[WARN] 插入1000條數據使用時間是:1620
2019-12-07 01:24:08 [TestMain]-[WARN] 插入10000條數據使用時間是:15043
批量
2019-12-07 01:24:08 [TestMain]-[WARN] 插入100條數據使用時間是:71
2019-12-07 01:24:08 [TestMain]-[WARN] 插入1000條數據使用時間是:120
2019-12-07 01:24:08 [TestMain]-[WARN] 插入10000條數據使用時間是:511
測試操做步驟及設置狀況
Log4j設置日誌爲warn,事務自動提交,每次測試後,都清空數據庫,再進行下一次測試。delicacy與mybatis的測試交替進行。
簡析
delicacy的平均單條插入時候在比mybatis短,連續100條時delicacy的單條平均時間爲2ms,mybatis的單條平均爲4.8ms.隨着連續條數的增加到10000條,delicacy的單條平均時間爲1.4ms,此時mybatis的單條平均爲1.5ms.在測試樣本內,mybatis始終未能超越delicacy的單條插入能力。delicacy的批量插入時間顯著落後於mybatis。小樣本數量時delicacy與mybatis的批量插入時間較單條循環都有顯著提高,大樣本數量時,delicacy的批量插入時間趨近於單條循環時間。
父子表插入
Delicacy第一次
2019-12-07 23:09:41 [UnionTableTest]-[WARN] 插入100條數據使用時間是:1090
2019-12-07 23:09:52 [UnionTableTest]-[WARN] 插入1000條數據使用時間是:11048
2019-12-07 23:14:40 [UnionTableTest]-[WARN] 插入10000條數據使用時間是:287114
Delicacy第二次
2019-12-07 23:34:37 [UnionTableTest]-[WARN] 插入100條數據使用時間是:1366
2019-12-07 23:34:48 [UnionTableTest]-[WARN] 插入1000條數據使用時間是:11131
2019-12-07 23:39:34 [UnionTableTest]-[WARN] 插入10000條數據使用時間是:286707
Delicacy第三次
2019-12-07 23:47:15 [UnionTableTest]-[WARN] 插入100條數據使用時間是:1085
2019-12-07 23:47:26 [UnionTableTest]-[WARN] 插入1000條數據使用時間是:11096
2019-12-07 23:52:25 [UnionTableTest]-[WARN] 插入10000條數據使用時間是:299705
Mybatis第一次
2019-12-09 23:44:45 [UnionTest]-[WARN] 插入100條數據使用時間是:828
2019-12-09 23:44:49 [UnionTest]-[WARN] 插入1000條數據使用時間是:3456
2019-12-09 23:45:22 [UnionTest]-[WARN] 插入10000條數據使用時間是:32876
Mybatis第二次
2019-12-09 23:47:05 [UnionTest]-[WARN] 插入100條數據使用時間是:812
2019-12-09 23:47:08 [UnionTest]-[WARN] 插入1000條數據使用時間是:3524
2019-12-09 23:47:41 [UnionTest]-[WARN] 插入10000條數據使用時間是:32764
Mybatis第三次
2019-12-09 23:48:27 [UnionTest]-[WARN] 插入100條數據使用時間是:809
2019-12-09 23:48:31 [UnionTest]-[WARN] 插入1000條數據使用時間是:3504
2019-12-09 23:49:03 [UnionTest]-[WARN] 插入10000條數據使用時間是:32259
簡析
父子表插入時,mybatis的時間稍大於delicacy的時間,單就持久層來看mybatis更強。其主要緣由有兩點:第一,mybatis沒有關心插入時的子表記錄的清洗,是純的持久層,而delicacy在插入時,根據入參不一樣,清理的原來的明細信息。第二,從以前的記錄看,mybatis在單表批量插入的時候性能遠超delicacy,也以在這次測試時,咱們使用1條記錄5條明細的插入對mybatis批量插入有優點。
測試後我及時向此框架的開發者反饋了單表批量插入狀況,開發者也做出了及時的針對mysql數據庫的優化,咱們在最後完成測試計劃後再作驗證。
多線程單表插入
Delicacy第一次
2019-12-11 22:00:10 [MultiThreadInsert]-[WARN] 10個線程併發完成100000條插入的時間是26933
Delicacy第二次
2019-12-11 22:00:58 [MultiThreadInsert]-[WARN] 10個線程併發完成100000條插入的時間是26624
Delicacy第三次
2019-12-11 22:06:34 [MultiThreadInsert]-[WARN] 10個線程併發完成100000條插入的時間是27119
Mybatis第一次
2019-12-11 21:49:08 [MultiThreadInsert]-[WARN] 10個線程併發完成100000條插入的時間是28075
Mybatis第二次
2019-12-11 21:50:49 [MultiThreadInsert]-[WARN] 10個線程併發完成100000條插入的時間是27891
Mybatis第三次
2019-12-11 21:51:30 [MultiThreadInsert]-[WARN] 10個線程併發完成100000條插入的時間是27884
簡析
多線程插入時,delicacy的速度比mybatis快。測試時使用了10線程的固定線程池,都使用了鏈接池,delicacy是線程綁定的鏈接池,mybatis是默認鏈接池,默認鏈接數是10。此結果從側面驗證了第一項測試的結果:單條插入delicacy比Mybatis快。
在測試時觀查到「Wed Dec 11 22:06:07 CST 2019 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.」這並非第一次出現,由於個人數據庫默認提示使用帳號密碼的鏈接,固jdbc驅動在WARN級別做出提示,但更奇怪的時,在給mybatis作測試的時候,此文本打印次數超過10次,爲348次,但從mysql workbench中監測到確實只有10個鏈接在工做,而delicacy的打印次數只有10次,workbench中也只有10個鏈接工做。說明Mybatis鏈接數據庫的次數超過了10次,總鏈接數正常,其默認鏈接池工做原理還有待深刻檢查。
單表查詢
Delicacy第一次
2019-12-11 23:48:11 [SingleTableSelect]-[WARN] 執行10000次查詢的時間是:3534
Delicacy第二次
2019-12-11 23:48:47 [SingleTableSelect]-[WARN] 執行10000次查詢的時間是:3343
Delicacy第三次
2019-12-11 23:49:01 [SingleTableSelect]-[WARN] 執行10000次查詢的時間是:3367
Mybatis第一次
2019-12-11 23:28:41 [SingleSelectTest]-[WARN] 執行10000次查詢的時間是:4043
Mybatis第二次
2019-12-11 23:29:03 [SingleSelectTest]-[WARN] 執行10000次查詢的時間是:4099
Mybatis第三次
2019-12-11 23:29:19 [SingleSelectTest]-[WARN] 執行10000次查詢的時間是:4027
簡析
在被邀請作此測試的時候已經預見到此結果,delicay的單表查詢比mybatis快。Delicay是生成器的目標代碼,在sql結果轉換成java Bean的時候使用了直接創造對象new,可是mybatis是通用持久層,只能用反射建立對象。Java反射一直比直接創造對象要慢。
父子表查詢
Delicacy第一次
2019-12-12 22:32:31 [UnionTableSelect]-[WARN] 執行10000次父子表查詢的時間是:5219
Delicacy第二次
2019-12-12 23:43:59 [UnionTableSelect]-[WARN] 執行10000次父子表查詢的時間是:4979
Delicacy第三次
2019-12-12 23:44:25 [UnionTableSelect]-[WARN] 執行10000次父子表查詢的時間是:4950
Mybatis第一次
2019-12-12 01:26:29 [UnionSelectTest]-[WARN] 執行10000次父子表查詢的時間是:2840
Mybatis第二次
2019-12-12 01:33:57 [UnionSelectTest]-[WARN] 執行10000次父子表查詢的時間是:2834
Mybatis第三次
2019-12-12 01:34:12 [UnionSelectTest]-[WARN] 執行10000次父子表查詢的時間是:2866
簡析
首先,當我看到父子表查詢消耗的時間少於單表查詢時,當即讓我覺得測試出了問題。檢查後發現是數據庫中的數據量變少了,單表查詢時User表中數據是60萬,如今user表中數據是5.5萬,Customer表中數據是1.1萬.而且user表中的customer_id字段作了索引(沒作索引時很慢,explan後發現user表被全表掃描)。
其次,Delicacy在作父子表查詢時對子表的查詢是獨立的查詢,而後把子表數據裝進返回對象的list中,因此在本次測試中10000次查詢,則delicacy實際進行了20000次查詢數據庫的操做,於是速度變慢。從具體的時間消息上也能夠證明此過程。
Web項目應用感覺
delicacy程序搭建:
Ssm 這個結構在國內網上有大把的樣板代碼,配置可整套複製而後修改便可,maven依賴各大倉庫都有。但值得說的是:ssm本人也好久沒有用過了,加上idea 社區版不能直接調試,在這個項目搭建上也折騰了好一會。再說delicacy,除數據鏈接和日誌外沒有配置,這個很爽。可是在啓動項目過程當中遇到兩次運行時異常,一次爲缺乏commons-fileupload,一次爲缺乏表column_domains。特地把這兩個提出來講的緣由是,我並無用到文件上傳,也並無用到column_domains表,這是delicacy的兩個隱藏依賴,成功知足後,項目順利運行。
運行:
1.在程序中寫了一個用隨機id查詢用戶並返回json的接口,二者的簡易程序至關。Jmeter配置10線程測試得ssm的qps爲13945.1,而delicacy的爲7846.2。分析發現delicacy框架在warn級別打出了日誌
2019-12-16 23:01:44 [delicacy.servlet.DelicacyServlet]-[WARN]
2019-12-16 23:01:44 [delicacy.servlet.DelicacyServlet]-[WARN] "id":13780,"account":"n","password":"h","userName":"z","customerId":2756,"a":"f","b":"f","c":"f","d":"i","e":"e","f":"z","g":"m"
此日誌爲詳細輸入參數與輸出結果,ssm沒有日誌。我認爲輸入輸出日誌是調試日誌,框架應用在warn級別打印此日誌略有不妥,其它開源框架通常打印在debug,或trace級別。
盡最大努力排除日誌因素影響,把delicacy的日誌級別調到error級別後測得QPS爲12810.7。這個結果讓我驚訝,前面的測試,單表查詢,與結果集解析,都是delicacy以10-20%的優點勝出 ,爲何輸出到客戶端的吞吐量要比ssh的小呢?
2.delicay生成一個父子關係的表查詢,很容易就能查詢並返回父子結構的數據,這個是很不錯的功能。也是在開發中經常使用到的。可是在前期咱們知道delicacy的子表信息是屢次查詢獲得的,爲非最佳效率的方法。就此我考慮專門寫一個sql語句給生成器,專門執行這個查詢任務。
3.寫了一個查詢,使用到四張表,客戶,聯繫人,客戶聯繫人關係,用戶(各表中都有Create_user_id,連上用戶表以把id轉換爲名字),一次性得到該客戶的全部詳細的可顯示的信息。生成器爲咱們生成了符合sql返回列的數據,條件查詢部分很輕鬆實現了。實際操做中較難序列化爲父子關係的json,這裏我並無使用用開源的第三方json序列化工具,而是試圖像框架的代碼同樣讓對象本身實現本身的tojson(),但手寫代碼太痛苦了。參見類中註釋uroaming.processor.ThreeTableProc
至此delicay的體驗就寫完了,基於我是一個平時使用mybatis用戶情形,以上點評較多存在主觀感覺。我相信較爲熟悉delicay的用戶可能有更好的實踐方案,以致於更好的應用delicacy.
mybatis程序搭建:
爲了與delicay同樣使用放在tomcat中的war運行項目,我特地使用的srping mvc對mybatis賦能,而不是springboot。Mvc的xml配置仍是須要花不少時間,特別是貿然使用了5版本的mvc,一個坑是classPath:字符串的寫法,之前是純小寫,如今有的地方要與大寫,有的要寫小寫classpath。而後配置mybatis到spring bean窗口,直接在網上抄來了。
運行:
1.寫一個用隨機id查詢用戶並返回json的接口,也正是上文中的例子。Spring運行時報錯,沒法轉換爲json。加入jackson三jar後解決。 這裏須要說明一下,在delicacy中的缺乏包的狀況:缺乏commons-fileupload包的時候,我並無須要上傳文件的功能。而缺乏jackson包時,我正在使用@ResponseBody要求spring將對象轉換爲json。
2.對於mybatis來講,delicay 第二項和第三項應用幾乎雷同,直接執行delicacy的第三項業務,寫xml動態sql的時候,每一個字母都是鍵盤敲擊出來,大量看上去有規律重複的條件讓人發狂。還要每個屬性去核對出入參的屬性,太傷人了。
附加測試
在測試的途中,頗有幸與delicacy的開發者創建聯繫,開發者瞭解到mysql對insert批量插入語句有特殊的支持時,更改了代碼針對mysql優化,幫再此測一遍delicacy批量單線程插入性能;
Delicacy優化前:
2019-12-07 01:14:48 [TestMain]-[WARN] 插入100條數據使用時間是:168
2019-12-07 01:14:49 [TestMain]-[WARN] 插入1000條數據使用時間是:1389
2019-12-07 01:15:03 [TestMain]-[WARN] 插入10000條數據使用時間是:13736
優化後第一次
2019-12-19 22:22:09 [SingleTableInsert]-[WARN] 插入100條數據使用時間是:34
2019-12-19 22:22:10 [SingleTableInsert]-[WARN] 插入1000條數據使用時間是:60
2019-12-19 22:22:10 [SingleTableInsert]-[WARN] 插入10000條數據使用時間是:268
優化後第二次
2019-12-19 22:24:09 [SingleTableInsert]-[WARN] 插入100條數據使用時間是:34
2019-12-19 22:24:09 [SingleTableInsert]-[WARN] 插入1000條數據使用時間是:61
2019-12-19 22:24:10 [SingleTableInsert]-[WARN] 插入10000條數據使用時間是:258
優化後第三次
2019-12-19 22:24:22 [SingleTableInsert]-[WARN] 插入100條數據使用時間是:32
2019-12-19 22:24:22 [SingleTableInsert]-[WARN] 插入1000條數據使用時間是:60
2019-12-19 22:24:22 [SingleTableInsert]-[WARN] 插入10000條數據使用時間是:264
分析:
優化後的性能發生質的飛躍,同時超過了mybatis的性能。
Delicay的sql解析與mybatis的動態sql測試
因爲sql解析後查數據庫的性能在以前的測試中已經有了較爲詳細的比較,而且我認爲sql解析的時間會遠小於數據庫的查詢執行時間,因此爲了不數據庫的查詢時間抖動讓解析性能測不出,我在這項測試中用動態修改字節碼的技術,把程序解析完成以後,準備發送到jdbc驅動以查詢數據庫以前的時間計算出來,把真實查詢數據庫的過程祛除。測試sql有15個條件所有設置查詢值。
Delicacy第一次
2019-12-21 00:00:36 [uroaming.SqlParseTest]-[WARN] delicacy解析10000次條件查詢sql的時間是:1163
Delicacy第二次
2019-12-21 00:00:51 [uroaming.SqlParseTest]-[WARN] delicacy解析10000次條件查詢sql的時間是:1170
Delicacy第三次
2019-12-21 00:01:03 [uroaming.SqlParseTest]-[WARN] delicacy解析10000次條件查詢sql的時間是:1148
Mybatis第一次
2019-12-21 01:42:32 [fu.dan.qi.testmybatis.SqlParseTest]-[WARN] mybatis 解析10000次條件查詢sql的時間是:1551
Mybatis第二次
2019-12-21 01:42:53 [fu.dan.qi.testmybatis.SqlParseTest]-[WARN] mybatis 解析10000次條件查詢sql的時間是:1544
Mybatis第三次
2019-12-21 01:43:03 [fu.dan.qi.testmybatis.SqlParseTest]-[WARN] mybatis 解析10000次條件查詢sql的時間是:1553
分析:mybatis解析sql的速度慢於delicacy,這當中已經祛除了真實的查數據庫的影響。只有查詢,固定返回空結果,封裝java對象。我認爲緣由是mybatis使用反射,加載插件(此次沒有插件)等因素致使代碼調用鏈複雜所致。而生成器後成的delicacy代碼是已知類型操做,代碼調用鏈較短。
寫在最後
本人水平有限,此次對比結果到這裏就告一段落,整體的感受是delicay用了不一樣於國內流行的常規開發方法,不一樣的設計結構,利用了生成器對特定項目的優點,巧妙的提高了很多的性能,而對新工具,方法的熟練須要項目來鍛鍊,如能精通則開發效率的提升還有更大的空間。