HouseMD是淘寶的聚石寫的一個非常優秀的Java進程運行時診斷和調試工具,如果你接觸過btrace,那么HouseMD也許你應該嘗試下,它比btrace更易用,不需要寫腳本,類似strace的方式attach到jvm進程做跟蹤調試。
基本的安裝和使用請看這篇文檔《
UserGuide》,恕不重復。以下內容都假設你正確安裝了housemd。
本文主要介紹下怎么用housemd診斷跟蹤clojure進程。Clojure的java實現也是跑在JVM里,當然也可以用housemd。
我們以一個簡單的例子開始,假設我們有如下clojure代碼:
(loop [x 1]
(Thread/sleep 1000)
(prn x)
(recur (inc x)))
這段很簡單,只是間隔一秒不斷地打印遞增的數字x。我們準備用housemd跟蹤這個程序的運行,首先運行這個程序,你可以用lein,也可以直接java命令運行:
java -cp clojure.jar clojure.main test.clj
運行時不斷地在控制臺打印數字,通過jps或者ps查詢到該進程的id,假設為pid,使用housemd連接到該進程:
housemd <pid>
順利進入housemd的交互控制臺,通過help命令可以查詢支持的命令:
housemd> help
quit terminate the process.
help display this infomation.
trace display or output infomation of method invocaton.
loaded display loaded classes information.
要用housemd調試clojure,你需要對clojure的實現有一點點了解,有興趣可以看過去的一篇blog《
clojure hacking guide》,簡單來說,clojure的編譯器會將clojure代碼編譯成java類并運行。對于JVM來說,clojure生成的類,跟java編譯器生成類沒有什么不同。
具體到上面的clojure代碼,會生成一個名為
user$eval1的類,user是默認的namespace,而eval1是clojure編譯器自動生成的一個標示類名,通過
loaded命令查詢類的加載情況:
housemd> loaded user$eval1 -h
user$eval1 -> null
- clojure.lang.DynamicClassLoader@1d25d06e
- clojure.lang.DynamicClassLoader@1d96f4b5
- sun.misc.Launcher$AppClassLoader@a6eb38a
- sun.misc.Launcher$ExtClassLoader@69cd2e5f
通過-h選項打印了加載user$eval1的類加載器的層次關系,因為user$eval1是動態生成的(clojure啟動過程中),因此它不在任何一個class或者jar文件中。除了查詢user namespace的類之外,你還可以查詢clojure.core,clojure.lang,clojure.java等任何被加載進來的類,例如查詢clojure.core.prn的類,在clojure里這是一個函數,在jvm看來這只是一個類:
housemd> loaded -h core$prn
clojure.core$prn -> /Volumes/HDD/Users/apple/clojure/clojure.jar
- sun.misc.Launcher$AppClassLoader@a6eb38a
- sun.misc.Launcher$ExtClassLoader@69cd2e5f
注意,不需要完整的namespace——clojure.core,直接core$prn即可。其他也是類似。
小技巧:如果你實在不知道clojure編譯器生成的類名,你可以利用jvm自帶的jmap命令來查詢。 接下來,我們嘗試用trace命令跟蹤方法的運行,例如例子中的clojure代碼用到了loop和recur兩個sepcial form,我們跟蹤下loop:
housemd> trace -t 5 core$loop
INFO : probe class clojure.core$loop
core$loop.doInvoke(Object, Object, Object, Object) sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
core$loop.getRequiredArity() sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
core$loop.doInvoke(Object, Object, Object, Object) sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
core$loop.getRequiredArity() sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
core$loop.doInvoke(Object, Object, Object, Object) sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
core$loop.getRequiredArity() sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
core$loop.doInvoke(Object, Object, Object, Object) sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
core$loop.getRequiredArity() sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
core$loop.doInvoke(Object, Object, Object, Object) sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
core$loop.getRequiredArity() sun.misc.Launcher$AppClassLoader@a6eb38a 0 -ms null
INFO : Ended by timeout
INFO : reset class clojure.core$loop
在5秒內,clojure.core$loop類有兩個方法各被調用了5次,doInvoke是實際的調用,而getRequiredArity用來查詢loop所需要的參數個數。trace還可以跟蹤到具體的方法,例如我們跟蹤prn函數的調用情況:
housemd> trace -t 5 core$prn.doInvoke
INFO : probe class clojure.core$prn
core$prn.doInvoke(Object) sun.misc.Launcher$AppClassLoader@a6eb38a 1 1ms clojure.core$prn@3e4ac866
core$prn.doInvoke(Object) sun.misc.Launcher$AppClassLoader@a6eb38a 2 <1ms clojure.core$prn@3e4ac866
core$prn.doInvoke(Object) sun.misc.Launcher$AppClassLoader@a6eb38a 3 <1ms clojure.core$prn@3e4ac866
core$prn.doInvoke(Object) sun.misc.Launcher$AppClassLoader@a6eb38a 4 <1ms clojure.core$prn@3e4ac866
core$prn.doInvoke(Object) sun.misc.Launcher$AppClassLoader@a6eb38a 5 <1ms clojure.core$prn@3e4ac866
INFO : Ended by timeout
INFO : reset class clojure.core$prn
trace打印了方法的調用次數(5秒內)和每次調用的時間(毫秒級別),以及調用的target object
。小技巧:沒有可變參數的函數生成類最終調用的是invoke方法(參數個數可能重載),有可變參數的函數調用的是doInvoke方法。
trace命令還支持打印調用堆棧到文件,例如:
trace -t 5 -d -s core$prn.doInvoke
利用-s和-d命令會將詳細的調用信息輸出到臨時目錄,臨時目錄的路徑可以通過trace help命令查詢到,在我的機器上是/tmp/trace/<pid>@host目錄下。調用堆棧的輸出類似:
example$square.invoke(Long) call by thread [main]
example$eval9.invoke(test.clj:11)
clojure.lang.Compiler.eval(Compiler.java:6465)
clojure.lang.Compiler.load(Compiler.java:6902)
clojure.lang.Compiler.loadFile(Compiler.java:6863)
clojure.main$load_script.invoke(main.clj:282)
clojure.main$script_opt.invoke(main.clj:342)
clojure.main$main.doInvoke(main.clj:426)
clojure.lang.RestFn.invoke(RestFn.java:421)
clojure.lang.Var.invoke(Var.java:405)
clojure.lang.AFn.applyToHelper(AFn.java:163)
clojure.lang.Var.applyTo(Var.java:518)
clojure.main.main(main.java:37)
上面這個簡單的例子展示了使用housemd跟蹤診斷clojure進程的方法。
自定義ns和函數的調試與此類似,假設我們有下面的clojure代碼:
(ns example)
(defn square [x]
(* x x))
(loop [x 1]
(Thread/sleep 1000)
(square x)
(recur (inc x)))
ns為example,自定義函數square并定期循環調用。使用housemd診斷這段代碼:
loaded -h example$square #查詢square的加載情況
trace -t 10 -d -s example$square.invoke #跟蹤10秒內square的調用情況