系統技術非業餘研究 » Iostat看不到裝置統計資訊的原因分析
最近在把玩些高速的SSD和nvram裝置的時候，發現iostat無法統計到這些裝置的資訊，很是奇怪，於是分析和總結了一把，挺有意思的。
現象描述如下：
# uname -a
Linux dr4000 2.6.32-131.17.1.el6.x86_64 #1 SMP Wed Oct 5 17:19:54 CDT 2011 x86_64 x86_64 x86_64 GNU/Linux
# ls -al /dev/nvdisk0
brw-rw-r– 1 root root 252, 0 Mar 10 16:18 /dev/nvdisk0
# iostat -d
Linux 2.6.32-131.17.1.el6.x86_64 (dr4000) 03/10/2012 _x86_64_ (24 CPU)Device: tps Blk_read/s Blk_wrtn/s Blk_read Blk_wrtn
sda 60.74 200.21 95.44 55171731 26299534
iostat很奇怪的看不到nvdisk0的IO統計資訊.
開始我們的分析之旅，先簡單的用strace看下iostat從那裡讀取這些統計資訊的：
# strace iostat -d
execve("/usr/bin/iostat", ["iostat", "-d"], [/* 25 vars */]) = 0
...
open("/sys/devices/system/cpu", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
fcntl(3, F_GETFD) = 0x1 (flags FD_CLOEXEC)
getdents(3, /* 35 entries */, 32768) = 1056
stat("/sys/devices/system/cpu/cpu0", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
...
getdents(3, /* 0 entries */, 32768) = 0
close(3) = 0
open("/proc/diskstats", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ffa8ea55000
read(3, " 1 0 ram0 0 0 0 0 0 0 0 "..., 1024) = 1024
read(3, "881869 2312902 26299638 3731982 "..., 1024) = 464
read(3, "", 1024) = 0
close(3) = 0
munmap(0x7ffa8ea55000, 4096) = 0
open("/etc/localtime", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=405, ...}) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=405, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ffa8ea55000
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\3\0\0\0\3\0\0\0\0"..., 4096) = 405
lseek(3, -240, SEEK_CUR) = 165
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\3\0\0\0\3\0\0\0\0"..., 4096) = 240
close(3) = 0
munmap(0x7ffa8ea55000, 4096) = 0
uname({sys="Linux", node="dr4000", ...}) = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 23), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ffa8ea55000
write(1, "Linux 2.6.32-131.17.1.el6.x86_64"..., 73Linux 2.6.32-131.17.1.el6.x86_64 (dr4000) 03/10/2012 _x86_64_ (24 CPU)
) = 73
write(1, "\n", 1
) = 1
rt_sigaction(SIGALRM, {0x404230, [ALRM], SA_RESTORER|SA_RESTART, 0x3ff7c32ac0}, {SIG_DFL, [], 0}, 8) = 0
alarm(0) = 0
munmap(0x7ffa8ea55000, 4096) = 0
open("/proc/uptime", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ffa8ea55000
read(3, "275660.93 6524235.15\n", 1024) = 21
close(3) = 0
munmap(0x7ffa8ea55000, 4096) = 0
open("/proc/stat", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ffa8ea55000
read(3, "cpu 1702243 167 1971793 6524235"..., 1024) = 1024
read(3, "0\ncpu20 26162 0 16915 27374407 1"..., 1024) = 1024
read(3, " 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0"..., 1024) = 1024
read(3, " 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0"..., 1024) = 797
read(3, "", 1024) = 0
close(3) = 0
munmap(0x7ffa8ea55000, 4096) = 0
open("/proc/diskstats", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ffa8ea55000
read(3, " 1 0 ram0 0 0 0 0 0 0 0 "..., 1024) = 1024
access("/sys/block/ram0", F_OK) = 0
open("/etc/sysconfig/sysstat.ioconf", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=6253, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ffa8ea54000
read(4, "#\n# sysstat.ioconf\n#\n# Copyrigh"..., 4096) = 4096
read(4, "8:7:\n136:48:8:\n137:48:9:\n138:48:"..., 4096) = 2157
read(4, "", 4096) = 0
close(4) = 0
munmap(0x7ffa8ea54000, 4096) = 0
access("/sys/block/ram1", F_OK) = 0
..
access("/sys/block/loop7", F_OK) = 0
read(3, "881869 2312902 26299638 3731982 "..., 1024) = 464
access("/sys/block/sda", F_OK) = 0
...
access("/sys/block/nvdisk0", F_OK) = 0
read(3, "", 1024) = 0
close(3) = 0
munmap(0x7ffa8ea55000, 4096) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=405, ...}) = 0
write(1, "", 0) = 0
write(1, "Device: tps", 22Device: tps) = 22
write(1, " Blk_read/s Blk_wrtn/s Blk"..., 49 Blk_read/s Blk_wrtn/s Blk_read Blk_wrtn
) = 49
write(1, "sda ", 13sda ) = 13
write(1, " 60.72 200.14 95"..., 58 60.72 200.14 95.41 55171731 26299638
) = 58
write(1, "\n", 1
) = 1
exit_group(0) = ?
很容易看出，主要IO相關資訊是從/proc/diskstats讀取的。 我們再來看下這個檔案的內容：
# cat /proc/diskstats 1 0 ram0 0 0 0 0 0 0 0 0 0 0 0 .. 1 15 ram15 0 0 0 0 0 0 0 0 0 0 0 7 0 loop0 0 0 0 0 0 0 0 0 0 0 0 .. 7 7 loop7 0 0 0 0 0 0 0 0 0 0 0 8 0 sda 11856307 92646 55171731 7784368 4881904 2312902 26299918 3731991 0 397111 11495597 ... 8 5 sda5 11832182 79153 54227969 7705146 4618019 600324 10473322 1854282 0 314124 9538788 252 0 nvdisk0 0 0 0 0 0 0 0 0 0 0 0
順手開啟核心程式碼block/genhd.c可以看到和diskstats統計相關的程式碼：
seq_printf(s, "%4d %4d %s %lu %lu %llu %u %lu %lu %llu %u %u %u %u\n",
gp->major, n + gp->first_minor, disk_name(gp, n, buf),
disk_stat_read(gp, ios[0]), disk_stat_read(gp, merges[0]),
(unsigned long long)disk_stat_read(gp, sectors[0]),
jiffies_to_msecs(disk_stat_read(gp, ticks[0])),
disk_stat_read(gp, ios[1]), disk_stat_read(gp, merges[1]),
(unsigned long long)disk_stat_read(gp, sectors[1]),
jiffies_to_msecs(disk_stat_read(gp, ticks[1])),
gp->in_flight,
jiffies_to_msecs(disk_stat_read(gp, io_ticks)),
jiffies_to_msecs(disk_stat_read(gp, time_in_queue)));
這些欄位的意義如下：
Field 1 — # of reads issued
Field 2 — # of reads merged, field 6 — # of writes merged
Field 3 — # of sectors read
Field 4 — # of milliseconds spent reading
Field 5 — # of writes completed
Field 7 — # of sectors written
Field 8 — # of milliseconds spent writing
Field 9 — # of I/Os currently in progress
Field 10 — # of milliseconds spent doing I/Os
Field 11 — weighted # of milliseconds spent doing I/Os
更具體的參看 這裡。
上面的現象的直接原因是由於我們的裝置nvdisk0統計值全0引起的。
那為什麼這些值全部是空的呢，顯然是裝置沒有把這些資訊暴露出來。 我們看下核心更新這些統計值的部分。
注意：為了簡單我就抄了2.6.18相關程式碼，因為他的程式碼集中在 ll_rw_blk.c 檔案中，而2.6.32分散到其他檔案，不好交代事情。
$ grep -rin _stat_add . ./ll_rw_blk.c:2744: __disk_stat_add(disk, time_in_queue, ./ll_rw_blk.c:2746: __disk_stat_add(disk, io_ticks, (now - disk->stamp)); ./ll_rw_blk.c:2762: part_stat_add(part, time_in_queue, ./ll_rw_blk.c:2764: part_stat_add(part, io_ticks, (now - ps->stamp)); ./ll_rw_blk.c:3379: all_stat_add(req->rq_disk, sectors[rw], ./ll_rw_blk.c:3402: __all_stat_add(disk, ticks[rw], duration, req->sector);
呼叫點主要是blk_account_io_done和blk_account_io_completion，而最終的源頭是void end_request(struct request *req, int uptodate)； 也就是說如果裝置驅動程式不呼叫 end_request之類的函式更新統計的話，那我們就得不到。
我們的nvdisk0是marvell造的nvram卡，目前不單賣，幸運的隨機廠家附送了驅動程式程式碼(謝謝老棟同學指出困惑)，我們來看下：
mvwam-1.6.2/driver/lokidrv.c
#define NV_BDEV_SECTOR_SZ 512
static int
nv_bdev_create(nvram_hba_t *nvhba)
{
...
/*
* Initialize block device queue
*/
gd->queue = blk_alloc_queue(GFP_KERNEL);
...
blk_queue_make_request(gd->queue, nvram_make_request);
...
blk_queue_hardsect_size(gd->queue, NV_BDEV_SECTOR_SZ);
...
}
*
* Entry of block I/O
*
* This function will construct prepare and submit block I/O to the queue
*
* @q - request queue from bio layer
* @bio - block io request
*
* @return 0 any way, extra info will be returned in nvram_endio
*/
static int
nvram_make_request(struct request_queue *q, struct bio *bio)
{
...
dma_req = kmem_cache_alloc(nv_dma_req_cache, GFP_KERNEL);
if (dma_req == NULL)
return -ENOMEM;
memset(dma_req, 0, sizeof(*dma_req));
dma_req->dma_next = NULL;
...
dma_req->dma_done = nv_blk_req_done;
...
bio_for_each_segment(bvec, bio, segno) {
paddr = (page_to_pfn(bvec->bv_page) << PAGE_SHIFT)
+ bvec->bv_offset;
valid_bytes = bvec->bv_len;
ret = host_prd_try_merge(&cntxt, paddr, valid_bytes);
if (ret != 0) {
/* max prd limit reached. need to split io */
ret = nv_split_io(nvhba, &dma_req, rw,
&offset, &cntxt);
if (ret != 0) {
goto prep_err;
}
nr_splits++;
host_prd_try_merge(&cntxt, paddr, valid_bytes);
}
}
...
}
該驅動直接在nvram_make_request中DMA的幹活了，為了效能就不走標準的IO請求佇列，所以也就不會呼叫和佇列功能相關的end_request函式。
深層次的原因找到了！
其實還有其他的硬體廠商做的裝置為了效能，在這塊對使用者不是太友好，不知道能不能改進下，尊重使用者的使用習慣！
小結：有原始碼，一切瞭然！
祝大家玩得開心！
Post Footer automatically generated by wp-posturl plugin for wordpress.
相關推薦
系統技術非業餘研究 » Iostat看不到裝置統計資訊的原因分析
最近在把玩些高速的SSD和nvram裝置的時候，發現iostat無法統計到這些裝置的資訊，很是奇怪，於是分析和總結了一把，挺有意思的。 現象描述如下： # uname -a Linux dr4000 2.6.32-131.17.1.el6.x86_64 #1 SMP Wed Oct 5 17:1
系統技術非業餘研究 » oprofile抓不到取樣資料問題和解決方法
最近有同學反映在某些新機器上做效能調優的時候， oprofile 有時抓不到資料，我之前也遇到這個情況，很是無語，今天特地驗證了下。 # 我們的作業系統和機器配置大概是這樣的： $sudo aspersa/summary # Aspersa System Summary Report ##
系統技術非業餘研究 » gen_tcp接受連結時enfile的問題分析及解決
最近我們為了安全方面的原因，在RDS伺服器上做了個代理程式把普通的MYSQL TCP連線變成了SSL連結，在測試的時候，皓庭同學發現Tsung發起了幾千個TCP連結後Erlang做的SSL PROXY老是報告gen_tcp:accept返回{error, enfile}錯誤。針對這個問題，我展開了
系統技術非業餘研究 » systemtap全域性變數自動列印的原因和解決方法
在執行stap的時候,經常會發現在指令碼結束執行的時候打出了很多無預期的東西,仔細一看都是些全域性變數的dump, 這個問題比較煩人. 我來演示下: $ cat > g.stp global xyz probe begin{ xyz=2010 exit(); } CT
系統技術非業餘研究 » gen_tcp傳送程序被掛起起因分析及對策
最近有同學在gmail上問關於gen_tcp傳送程序被掛起的問題，問題描述的非常好，見底下： 第一個問題是關於port_command和gen_tcp:send的。從專案上線至今，我在tcp傳送的地方遇到過兩次問題，都跟port_command有關係。 起初程式的效能不好，我從各方面嘗試分析和優化
系統技術非業餘研究 » gen_tcp傳送緩衝區以及水位線問題分析
前段時間有同學在線上問了個問題： 伺服器端我是這樣設的：gen_tcp:listen(8000, [{active, false}, {recbuf,1}, {buffer,1}]). 客戶端是這樣設的：gen_tcp:connect(“localhost”, 8000, [{active, f
系統技術非業餘研究 » 計算機各系統元件的吞吐量和延遲 看圖不說話
這個圖挺好的，就是比較粗線條，有些東西不太完整/準確，比如現有的USB實際上是480M/12M和1.5M三種速率（暫不算3.0和無線的） 另：幫樓主補充一下這類資料的意義：如果對各種匯流排的速率和IOPS如果沒有概念和預估，寫程式時就只能Compile & Pray了。 Reply:O
系統技術非業餘研究 » MYSQL資料庫網絡卡軟中斷不平衡問題及解決方案
最近公司在MySQL的資料庫上由於採用了高速的如PCIe卡以及大記憶體，去年在壓力測試的時候突然發現數據庫的流量可以把一個千M網絡卡壓滿了。隨著資料庫的優化，現在流量可以達到150M，所以我們採用了雙網絡卡，在交換機上繫結，做LB的方式，提高系統的吞吐量。 但是在最近壓測試的一個數據庫中，mps
系統技術非業餘研究 » 看圖學TCP API以及狀態變遷
client的connect呼叫和server端之間的三根線應該對應著三次握手過程，這裡有一點問題。 client傳送的sync到達應該在server端accpet之前，所以橙色線應該指向accpet前面。 同樣，server端響應ack,sync是在accpet呼叫前的，因此粉色線也應該放在a
系統技術非業餘研究 » TCP連結主動關閉不發fin包奇怪行為分析
問題描述： 多隆同學在做網路框架的時候，發現一條tcp連結在close的時候，對端會收到econnrest,而不是正常的fin包. 通過抓包發現close系統呼叫的時候，我端發出rst報文, 而不是正常的fin。這個問題比較有意思，我們來演示下： $ erl Erlang R14B03 (e
系統技術非業餘研究 » 看multitrace程式碼學習如何定製自己的dbg資訊
multitrace是ttb應用帶的一個例子，給了個例子讓使用者來格式化和定製自己的dbg資訊。 文件在這裡： The module multitrace.erl which can be found in the src directory of the Observer application
系統技術非業餘研究 » systemtap函式呼叫棧資訊不齊的原因和解決方法
有時候在看系統程式碼的時候，我們很難從原始碼中看出我們感興趣的函式是如何被呼叫的，因為呼叫路徑有可能太多。使用者空間的程式gdb設斷點是個好的方法，核心的就麻煩了。這時候systemtap可以幫忙, 比如: $uname -r 2.6.18-164.el5 $stap -V Syste
系統技術非業餘研究
ItPub寫的文章“2017 年度 DB-Engines 資料庫冠軍得主：PostgreSQL 封王！”, 點選 這裡 進一步閱讀 升的最快的幾個資料庫，我簡單的無責任點評： PG資料庫是很老的資料庫，不過這幾年冉冉升起，因為是學院派的，有很好的學術和智力的支援，一直以來在資料庫的體系結構，程式碼
系統技術非業餘研究 » MySQL資料庫架構的演化觀察
MySQL資料庫架構的演化觀察 December 14th, 2017 Categories: 資料庫 Tags: mysql
系統技術非業餘研究 » inet_dist_connect_options
Erlang 17.5版本引入了inet_dist_{listen,connect}_options，對於結點間的互聯socket可以有更精細的控制，RPC的時候效能可以微調： raimo/inet_tcp_dist-priority-option/OTP-12476: Document ke
系統技術非業餘研究 » 推薦工作機會
最後更新時間：2014/11/28 請賜簡歷至：[email protected]， 感謝您對加入我們公司有興趣，我們希望能早日和您共事。 以下幾個職位1年內有效，歡迎內部轉崗： 資深資料工程師 公司：阿里（核心系統資料庫組） 工作地點：杭州（西溪園區） 崗位描述： 分析雲服務產生的海
系統技術非業餘研究 » 新的工作和研究方向
和大家更新下： 做了將近8年資料庫後，我的工作和研究方向將會延伸到虛擬化和計算相關的雲服務，希望能夠和大家一起進步，Happy New Year！ 預祝大家玩得開心！ Post Footer automatically generated by wp-posturl plugin for w
系統技術非業餘研究 » 叢集引入inet_dist_{listen,connect}_options更精細引數微調
Erlang 17.5版本引入了inet_dist_{listen,connect}_options，對於結點間的互聯socket可以有更精細的控制，RPC的時候效能可以微調： raimo/inet_tcp_dist-priority-option/OTP-12476: Document ke
系統技術非業餘研究 » 2017升的最快的幾個資料庫無責任點評
ItPub寫的文章“2017 年度 DB-Engines 資料庫冠軍得主：PostgreSQL 封王！”, 點選 這裡 進一步閱讀 升的最快的幾個資料庫，我簡單的無責任點評： PG資料庫是很老的資料庫，不過這幾年冉冉升起，因為是學院派的，有很好的學術和智力的支援，一直以來在資料庫的體系結構，程式碼
系統技術非業餘研究 » Erlang 17.5引入+hpds命令列控制程序預設字典大小
Erlang 17.5釋出引入控制程序預設字典大小的命令列引數： Erlang/OTP 17.5 has been released Written by Henrik, 01 Apr 2015 Some highlights of the release are: ERTS: Added co