簡介
ksh_timer 被設計用來幫助 ksh 或 ksh93 腳本管理員或開發人員計算每個函數及其 shell 腳本用戶定義部分所用的時間。
以下幾個要點定義了 ksh_timer 的功能：
如果在 ksh_timer 中運行腳本，那麼該腳本調用的函數是自動計時的。
用戶使用 ##KTB <section_name>（這部分的開始）和 ##KTE <section_name>（這部分的結束）在腳本中心 定義相關部分。
給出的時間是總運行時間，不是已使用的時間。
輸出包括 ? Main ? 時間，這是腳本的總運行時間。
還包括去向不明的輸出 時間，這些時間是花費在函數或用戶定義部分之外的 ? Main ? 部分中的時間。
去 向不明的時間還包括計算函數引起的 ksh_timer 開銷。
ksh_timer 支持 ksh 和 ksh93 腳本的執行。
使用：ksh_timer [-D] [-c] [-?] [-s] [script name arguments ...]
-D 將 ksh_timer 置於調試模式。
-c 保留原始輸出文件 (ksh_timer.<script_name>.<pid>.out)。通常在執行後刪除。
-s [script name arguments ...] 腳本文件名和腳本所需參數。
-? 打印使用情況。
重要提示
該接口 (ksh_timer) 是為了用戶方便而提供的。本文使用一個樣例程序說明了 ksh_timer 的用法和功能，工具 是按原樣提供的，我們不提供任何擔保和支持。
該工具已在 IBM? AIX? 5.3,6.1 和 7.1 版本上 進行了測試。ksh_timer 可以用於其他操作系統，要實現這一點，必須使用本文安裝 小節中提供的源代 碼，為該操作系統重新構建 ksh_timer_c 可執行文件。
概述
在啟動時，ksh_timer 會讀 取命令行提供的輸入腳本，然後從中構建以下 3 個文件（源文件、計時器文件和 exec 文件）。
源文件包含原函數定義，並且來自 exec 文件。
計時器文件包含包括計時代碼和調 用原函數的封裝函數。計時器文件也來自 exec 文件。在下列示例中，原函數 f1 在源文件中被重命名為 f1_orig ，而在計時器文件中，f1 有一個計時代碼包含 f1_orig 函數，該函數使我們能夠得到原函數 f1 所耗的時間。
exec 文件是源文件和計時器文件的來源，而且包含原始 main 代 碼以及用於任何用戶定義部分的計時器代碼。
當完成這些文件的構建之後，ksh_timer 會運行構 建 exec 文件。運行原始代碼時，該函數會計算函數和用戶定義部分的運行時間，並將這些時間寫入輸出 文件。執行完這些操作之後，它會分析輸出文件，然後計算函數名、縮進、迭代次數以及這些函數或代碼 部分的最小、最大、平均和總運行時間，並將它們顯示在屏幕上。
使用以下輸入腳本樣例： ksh_timer.test_pres
#! /usr/bin/ksh
f1()
{
echo "hello"
}
#Main
##KTB user_defined_section
sleep 1
f1
##KTE user_defined_section
sleep 2
f1
源文件：包含原始函數定義
f1_orig()
{
echo "hello"
}
計時器文件：包含包括計時代碼和調用原函數的封裝函數
function f1
{
time1f1=`/home/albl/ksh_timer/ksh_timer_c`
ksh_timer_add_func f1
f1_orig $*
f1_orig_rc=$?
time2f1=`/home/albl/ksh_timer/ksh_timer_c`
let " time3f1 = $time2f1 - $time1f1"
print "$indent1:$indent2:$indent3:$indent4:$indent5:$time3f1" >&9
ksh_timer_remove_func f1
return $f1_orig_rc
}
exec 文件：包含用於任何用戶定義部分的原始代碼和計時器代碼
. ./ksh_timer.test_pres.413914.source . ./ksh_timer.test_pres.413914.timer time1user_defined_section=`/home/albl/ksh_timer/ksh_timer_c` ksh_timer_add_func user_defined_section sleep 1 f1 time2user_defined_section=`/home/albl/ksh_timer/ksh_timer_c` let "time3user_defined_section=$time2user_defined_section-$time1user_defined_section" print "$indent1:$indent2:$indent3:$indent4:$indent5:$time3user_defined_section" >&9 ksh_timer_remove_func user_defined_section sleep 2 f1
運行該樣例得到下列輸出：
$ ./ksh_timer -s ./sample ----------------------Start of sample output-------------------------------- hello hello ----------------------End of sample output-------------------------------- ------------------------------------------------------------------------------------------ | function | Minimum | Maximum | Average | Total | | +-------------------+-------------------+------------+-------------------| | or Section |iter.#| time |iter.#| time | time |#iter.| time | |---------------+------+------------+------+------------+------------+------+------------| |Main | |0m03.092834s| |---------------+------+------------+------+------------+------------+------+------------| |-user_defined| 1|0m01.027853s| 1|0m01.027853s|0m01.027853s| 1|0m01.027853s| |--f1 | 1|0m00.003143s| 1|0m00.003143s|0m00.003143s| 1|0m00.003143s| |-f1 | 1|0m00.002652s| 1|0m00.002652s|0m00.002652s| 1|0m00.002652s| |---------------------------------------------------------------------------+------------| |-Unaccounted | |0m02.062329s| ------------------------------------------------------------------------------------------
正如我們所看到的，user_defined_section 被調用了一次，在 user_defined_section 中 f1 函數被調用了一次，在該腳本的主要部分中，f1 也被調用了一次。user_defined_section 所用時間是 1 秒多一點，這主要是步驟 1 以及 f1 函數所用的時間。去向不明時間大約有 2 秒，這主要是所有部分或 函數外部的步驟 2 所用時間，以及 ksh_timer 計算時間所需的開銷。
用戶定義部分計時器代碼 與執行代碼保持關聯，以便能夠在這些部分的內部使用傳遞給 shell 腳本的參數。ksh_timer 輸出將以 一種易於閱讀的表格形式發送到屏幕（稍後給出相關示例）。如果您選擇將輸出發送到某個文件，那麼將 以下列格式輸出每次迭代：
Main:indent1:…:indent9:>time_spent<
（縮進 1 到 9 的輸出可能是調用函數的函數名，或者如果函數深度沒有達到那麼深的話，輸出則為空。）例如 ：
Main:user_defined_section:f1:::::::3143
（我們在 f1 函數中花費的時間為 3143 微秒，user_defined 調用了該函數，而 user_defined 反過來是從主要部分調用的。）
安 裝 ksh_timer
您可以從 下載 部分下載 ksh_timer。
要完成安裝，首先應 該將 ksh_timer.tar 文件解壓到任意目錄下。
您可能需要編輯將要實現計時功能 的原始腳本來添加帶有 ? ##KTB <section_name> ? 和 ? ##KTE <section_name> 定義的用 戶定義部分。
要完成執行，請運行 ./ksh_timer –s <your_script>。
輸出被發送到屏幕上；如果指定了 –c 的話，則會將原始數據發送到文件 ksh_timer.<script name>.<PID>.out。
如果運行一個非 AIX 系統， ksh_timer_c 代碼需要從以下 ksh_timer_c.c 源代碼重構：
#include <stdio.h>
#include <sys/time.h>
main()
{
struct timeval Tp;
gettimeofday(&Tp,NULL);
printf("%lld\n",(unsigned long long)((Tp.tv_sec*1000000)+Tp.tv_usec));
}
使用示例
想象一下，如果有下列腳本 script_test_vmm，您可能想要評估 vmm_test2 所用時間，該函數在每次調用 rmss 之後才調用。您可能想要評估每個 rmss 所用的時間。
#!
/usr/bin/ksh
integer i=0
rmss -c 950
while [[ $i -lt 3 ]]
do
/tmp/ksh_timer/test_vmm2
i=i+1
done
rmss -c 1450
i=0
while [[ $i -lt 3 ]]
do
/tmp/ksh_timer/test_vmm2
i=i+1
done
步驟 1：通過使用適當的 ##KTB 並匹配的 ##KTE，編輯您的 script_test_vmm 腳本和 添加用戶定義部分，從而劃分您的用戶定義部分的界限，如下列代碼所示：
#! /usr/bin/ksh integer i=0 ##KTB rmss950 rmss -c 950 while [[ $i -lt 3 ]] do ##KTB vmm_test2 /tmp/ksh_timer/test_vmm2 i=i+1 ##KTE vmm_test2 done ##KTE rmss950 ##KTB rmss1450 rmss -c 1450 i=0 while [[ $i -lt 3 ]] do ##KTB vmm_test2 /tmp/ksh_timer/test_vmm2 i=i+1 ##KTE vmm_test2 done ##KTE rmss1450
步驟 2：使用 ksh_timer -s script_test_vmm 運行先前的腳本。
- ---------------------Start of script_test_vmm output-------------------------------- Simulated memory size changed to 950 Mb. Simulated memory size changed to 1450 Mb. ----------------------End of script_test_vmm output-------------------------------- ------------------------------------------------------------------------------------------ | Function | Minimum | Maximum | Average | Total | | +-------------------+-------------------+------------+-------------------| | or Section |iter.#| time |iter.#| time | time |#iter.| time | |---------------+------+------------+------+------------+------------+------+------------| |Main | |1m36.578814s| |---------------+------+------------+------+------------+------------+------+------------| |-rmss950 | 1|1m02.120269s| 1|1m02.120269s|1m02.120269s| 1|1m02.120269s| |--vmm_test2 | 3|0m16.813174s| 1|0m23.461610s|0m20.654322s| 3|1m01.962968s| |-rmss1450 | 1|0m34.416279s| 1|0m34.416279s|0m34.416279s| 1|0m34.416279s| |--vmm_test2 | 2|0m11.382110s| 3|0m11.427596s|0m11.402585s| 3|0m34.207757s| |---------------+-----------------------------------------------------------+------------| |-Unaccounted | |0m00.042266s| ------------------------------------------------------------------------------------------
查看本欄目更多精彩內容：http://www.bianceng.cn/OS/unix/
作為另一個示例，我們在 mksysb 腳本上運行 ksh_timer。通過編輯 mksysb 腳本，可以添加 一個名為 backup_files_in_list 的用戶定義部分。在以下輸出中我們可以看到，不僅僅對 backup_files_in_list 部分進行計時，而且對在腳本中定義的任何部分都進行了計時。通過查看輸出， 我們很容易發現，mksysb 腳本所用的最大時間在 backup_files_in_list 中，耗時 1m33.029798s，整個 腳本耗時 1m49.140307s。
# ksh_timer -s ./mksysb -i /dev/null ----------------------Start of mksysb output-------------------------------- Creating information file (/image.data) for rootvg. Creating list of files to back up Backing up 56510 files........ 56510 of 56510 files backed up (100%)0512-038 mksysb: Backup Completed Successfully. ----------------------End of mksysb output-------------------------------- ------------------------------------------------------------------------------------------ | Function | Minimum | Maximum | Average | Total | | +-------------------+-------------------+------------+-------------------| | or Section |iter.#| time |iter.#| time | time |#iter.| time | |---------------+------+------------+------+------------+------------+------+------------| |Main | |1m49.140307s| |---------------+------+------------+------+------------+------------+------+------------| |-set_up_environ| 1|0m00.048720s| 1|0m00.048720s|0m00.048720s| 1|0m00.048720s| |--fail_if_wpar | 1|0m00.005507s| 1|0m00.005507s|0m00.005507s| 1|0m00.005507s| |--getoptions | 1|0m00.012926s| 1|0m00.012926s|0m00.012926s| 1|0m00.012926s| |-create_temp_di| 1|0m00.007239s| 1|0m00.007239s|0m00.007239s| 1|0m00.007239s| |-if_rootvg | 1|0m00.153775s| 1|0m00.153775s|0m00.153775s| 1|0m00.153775s| |--tddupdate | 1|0m00.070964s| 1|0m00.070964s|0m00.070964s| 1|0m00.070964s| |--Get_Rootvg_IS| 1|0m00.042464s| 1|0m00.042464s|0m00.042464s| 1|0m00.042464s| |--tsddupdate | 1|0m00.027835s| 1|0m00.027835s|0m00.027835s| 1|0m00.027835s| |-if_device | 1|0m00.014855s| 1|0m00.014855s|0m00.014855s| 1|0m00.014855s| |-if_image_data | 1|0m05.132797s| 1|0m05.132797s|0m05.132797s| 1|0m05.132797s| |-make_backup_da| 1|0m00.350696s| 1|0m00.350696s|0m00.350696s| 1|0m00.350696s| |--get_backup_si| 1|0m00.031814s| 1|0m00.031814s|0m00.031814s| 1|0m00.031814s| |---get_stanza_d| 1|0m00.019862s| 1|0m00.019862s|0m00.019862s| 1|0m00.019862s| |-run_the_exclud| 1|0m05.697004s| 1|0m05.697004s|0m05.697004s| 1|0m05.697004s| |-backup_files| 1|1m33.029798s| 1|1m33.029798s|1m33.029798s| 1|1m33.029798s| |--kill_pid | 1|0m02.015270s| 2|0m02.020543s|0m02.017906s| 2|0m04.035813s| |-done_backup | 1|0m00.016388s| 1|0m00.016388s|0m00.016388s| 1|0m00.016388s| |--kill_pid | 1|0m02.015329s| 1|0m02.015329s|0m02.015329s| 1|0m02.015329s| |---------------------------------------------------------------------------+------------| |-Unaccounted | |0m04.689035s| ------------------------------------------------------------------------------------------
使用第 2 個示例，您也可以輕松地發現是否重復調用了一個函數或某個 部分，或者是否有些調用比其他調用更加耗時。例如，在這裡您可以看出，setcmd 在 init_pos_cmds 中 調用了 44 次，我們還可以看出，最大時間、最小時間和平均時間基本上都是常量。
第 3 個示例使用了 ksh_timer –s ./rpm_share –i 結果，該示例展示了 ksh_timer 中縮進的使 用，以及可在輸出中找到的各種信息。例如，我們可以發現：
在其他兩個函數中也調用了 setcmd ：在 init_pos_cmd 中調用了 44 次，在 init_sys_vars 中調用了 5 次。
查看最 小時間、最大時間和平均時間，我們可以看到，不同 setcmd 迭代之間沒有太大差量，不管是在 init_pos_cmd 調用還是從 init_sys_vars 調用。
# ksh_timer –s ./rpm_share –i … -----------------Start of rpm_share output-------------------------------- -----------------End of rpm_share output-------------------------------- ------------------------------------------------------------------------------------------ | Function | Minimum | Maximum | Average | Total | | +-------------------+-------------------+------------+-------------------| | or Section |iter.#| time |iter.#| time | time |#iter.| time | |---------------+------+------------+------+------------+------------+------+------------| |Main | |0m01.506875s| |---------------+------+------------+------+------------+------------+------+------------| |-init_baselib | 1|0m00.366488s| 1|0m00.366488s|0m00.366488s| 1|0m00.366488s| |--init_pos_cmd | 1|0m00.252172s| 1|0m00.252172s|0m00.252172s| 1|0m00.252172s| |---setcmd | 9|0m00.002762s| 5|0m00.002922s|0m00.002825s|44|0m00.124313s| |--init_sys_vars| 1|0m00.056660s| 1|0m00.056660s|0m00.056660s| 1|0m00.056660s| |---setcmd | 5|0m00.002860s| 2|0m00.002929s|0m00.002879s| 5|0m00.014397s| |---init_libinst| 1|0m00.014667s| 1|0m00.014667s|0m00.014667s| 1|0m00.014667s| |----inc | 1|0m00.008601s| 1|0m00.008601s|0m00.008601s| 1|0m00.008601s| |-----isnum | 1|0m00.002853s| 1|0m00.002853s|0m00.002853s| 1|0m00.002853s| |--ck_exp_fs | 1|0m00.035973s| 1|0m00.035973s|0m00.035973s| 1|0m00.035973s| |---isYorN | 1|0m00.002837s| 1|0m00.002837s|0m00.002837s| 1|0m00.002837s| |---whichfs | 1|0m00.004191s| 1|0m00.004191s|0m00.004191s| 1|0m00.004191s| |---getfsfree | 1|0m00.009434s| 1|0m00.009434s|0m00.009434s| 1|0m00.009434s| |----isnum | 1|0m00.002462s| 1|0m00.002462s|0m00.002462s| 1|0m00.002462s| |---isnum | 1|0m00.002952s| 1|0m00.002952s|0m00.002952s| 1|0m00.002952s| |--check_dir | 1|0m00.002905s| 1|0m00.002905s|0m00.002905s| 1|0m00.002905s| |-ck_exp_fs | 1|0m00.036059s| 2|0m00.036169s|0m00.036114s| 2|0m00.072228s| |--isYorN | 2|0m00.002875s| 1|0m00.002881s|0m00.002878s| 2|0m00.005756s| |--whichfs | 2|0m00.004239s| 1|0m00.004263s|0m00.004251s| 2|0m00.008502s| |--getfsfree | 1|0m00.009377s| 2|0m00.009382s|0m00.009379s| 2|0m00.018759s| |---isnum | 2|0m00.002425s| 1|0m00.002444s|0m00.002434s| 2|0m00.004869s| |--isnum | 2|0m00.003008s| 1|0m00.003030s|0m00.003019s| 2|0m00.006038s| |-set_time_token| 1|0m00.009403s| 1|0m00.009403s|0m00.009403s| 1|0m00.009403s| …snip… |--check_fdup_sp| 1|0m00.098203s| 1|0m00.098203s|0m00.098203s| 1|0m00.098203s| |---getfsize | 1|0m00.018850s| 1|0m00.018850s|0m00.018850s| 1|0m00.018850s| |----check_file | 1|0m00.002347s| 1|0m00.002347s|0m00.002347s| 1|0m00.002347s| |----isnum | 1|0m00.002366s| 1|0m00.002366s|0m00.002366s| 1|0m00.002366s| |---whichfs | 1|0m00.004378s| 1|0m00.004378s|0m00.004378s| 1|0m00.004378s| |---addbuf | 1|0m00.021044s| 1|0m00.021044s|0m00.021044s| 1|0m00.021044s| |----isnum | 3|0m00.002948s| 2|0m00.002962s|0m00.002956s| 3|0m00.008868s| |---ck_exp_fs | 1|0m00.036967s| 1|0m00.036967s|0m00.036967s| 1|0m00.036967s| |----isYorN | 1|0m00.002998s| 1|0m00.002998s|0m00.002998s| 1|0m00.002998s| |----whichfs | 1|0m00.004340s| 1|0m00.004340s|0m00.004340s| 1|0m00.004340s| |----getfsfree | 1|0m00.009691s| 1|0m00.009691s|0m00.009691s| 1|0m00.009691s| |-----isnum | 1|0m00.002514s| 1|0m00.002514s|0m00.002514s| 1|0m00.002514s| |----isnum | 1|0m00.002964s| 1|0m00.002964s|0m00.002964s| 1|0m00.002964s| |--cleanup | 2|0m00.002960s| 1|0m00.007511s|0m00.005235s| 2|0m00.010471s| |---------------------------------------------------------------------------+------------| |-Unaccounted | |0m00.141934s| ------------------------------------------------------------------------------------------
故障排除
如果在使用 ksh_timer 工具是發現任何的問題，那麼需要運行：
./ksh_timer –D –c –s <your_script> <script.debug.out 2>&1
將下列文件發送給代碼作者：
script.debug.out
<your_script>
csv 文件 ：ksh_timer. <your_script>.<pid>.out
結束語
ksh_timer 是一個簡單而又 方便的可定制工具，可用於估計腳本所用的時間。不需要修改腳本，只需運行一次，就可以了解該腳本最 耗時的函數。如果腳本沒有使用函數，或者大部分時間被該腳本的主部分占用，那麼用戶可以編輯該腳本 ，並在主要部分、甚至是函數中創建用戶定義部分，以便跟蹤耗時最多的某一行的詳細信息。ksh_timer 輸出分析可在耗時最多的用戶 shell 腳本中顯示部分代碼。如果該腳本其中一部分運行了另一個 shell 腳本，那麼用戶可能需要更改這些代碼，以便調用該腳本，使用 ksh_timer 對其進行計時。如果調用的 可執行文件不是一個 shell 腳本，那麼用戶需要使用其他可執行工具對其進行計時。
下載