質問をすることでしか得られない、回答やアドバイスがある。

15分調べてもわからないことは、質問しよう!

新規登録して質問してみよう
ただいま回答率
87.20%
CentOS

CentOSは、主にRed Hat Enterprise Linux(RHEL)をベースにした、フリーのソフトウェアオペレーティングシステムです。

Linux

Linuxは、Unixをベースにして開発されたオペレーティングシステムです。日本では「リナックス」と呼ばれています。 主にWebサーバやDNSサーバ、イントラネットなどのサーバ用OSとして利用されています。 上位500のスーパーコンピュータの90%以上はLinuxを使用しています。 携帯端末用のプラットフォームAndroidは、Linuxカーネル上に構築されています。

解決済

DISK I/Oが発生している要因

kenji267
kenji267

総合スコア0

CentOS

CentOSは、主にRed Hat Enterprise Linux(RHEL)をベースにした、フリーのソフトウェアオペレーティングシステムです。

Linux

Linuxは、Unixをベースにして開発されたオペレーティングシステムです。日本では「リナックス」と呼ばれています。 主にWebサーバやDNSサーバ、イントラネットなどのサーバ用OSとして利用されています。 上位500のスーパーコンピュータの90%以上はLinuxを使用しています。 携帯端末用のプラットフォームAndroidは、Linuxカーネル上に構築されています。

3回答

1評価

3クリップ

56閲覧

投稿2019/04/08 11:26

編集2022/01/12 10:58

前提・実現したいこと

さくらVPSを使用しております。
DISK I/Oが発生している要因を調査したいと考えています。
時々一時的に急激に上がったりしています。
なお特にアプリは動かしてはいません。

dstat -taf で、IO負荷を確認しています。
dsk/vdaで時々、writに値が発生しています。

これは書き込みが発生しているという認識でよろしいでしょうか。
その書き込みはどうやって発生しているか確認する方法はありますでしょうか。

ご教授のほどどうかよろしくお願いします。

調査したい箇所

一時的に増加している。
DISK I/O

調査例1

date/time |usr sys idl wai hiq siq:usr sys idl wai hiq siq| read writ| recv send| in out | int csw 08-04 19:52:10| 0 0 100 0 0 0: 0 0 100 0 0 0| 0 0 |1594B 442B| 0 0 | 57 27 08-04 19:52:11| 0 0 100 0 0 0: 0 0 100 0 0 0| 0 0 |1774B 442B| 0 0 | 48 19 08-04 19:52:12| 0 0 100 0 0 0: 0 0 100 0 0 0| 0 0 |1354B 442B| 0 0 | 58 19 08-04 19:52:13| 1 0 99 0 0 0: 0 0 100 0 0 0| 0 0 |1834B 442B| 0 0 | 51 19 08-04 19:52:14| 0 0 100 0 0 0: 0 0 100 0 0 0| 0 0 |1774B 442B| 0 0 | 45 17 08-04 19:52:15| 0 0 100 0 0 0: 0 0 100 0 0 0| 0 4096B|1594B 442B| 0 0 | 57 28 08-04 19:52:16| 0 0 100 0 0 0: 0 0 100 0 0 0| 0 0 |1714B 442B| 0 0 | 52 17

調査例2

上記に対しswapを確認

vmstat -t 2

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------ ---timestamp--- r b swpd free buff cache si so bi bo in cs us sy id wa st 0 0 0 264692 190432 363308 0 0 0 0 3 2 0 0 100 0 0 2019-04-08 20:56:48 JST 0 0 0 264668 190432 363308 0 0 0 0 49 20 0 0 100 0 0 2019-04-08 20:56:50 JST 0 0 0 264668 190432 363308 0 0 0 0 49 17 0 0 100 0 0 2019-04-08 20:56:52 JST 0 0 0 264668 190432 363308 0 0 0 44 45 20 0 0 100 0 0 2019-04-08 20:56:54 JST 0 0 0 264668 190432 363308 0 0 0 0 45 17 0 0 100 0 0 ``` ### 調査例3 ![イメージ説明](9010f3c2e0f6e5831e3ebcf7f04d9131.png) [sarコマンド](https://qiita.com/makaaso/items/6e27a2f0948241891667) proc/s.... 1秒あたりの生成されたプロセス数 cswch/s... 1秒あたりのコンテキストスイッチ回数 tps.............. 1秒間のI/Oリクエスト数(転送回数) rd_sec(rsec)/s... 1秒間の読み込みセクタ数(1セクタ512バイト) wr_sec(wsec)/s... 1秒間の書き込みセクタ数(1セクタ512バイト) avgrq-sz......... デバイスへのIOリクエストの平均セクタサイズ avgqu-sz......... デバイスへのIOリクエストの待ち行列の平均セクタサイズ await............ デバイスへのIOリクエストの平均待ち時間(単位msec)[待ち行列にいる時間+処理時間] svctm............ デバイスへのIOリクエストの平均処理時間(単位msec) %util............ デバイスへのIOリクエスト中のCPU使用率(ここが継続的に100%だとディスク部分でボトルネックになっている可能性が高い) --- /var/log/sa/sa08

00時00分01秒 proc/s cswch/s
00時10分01秒 0.01 15.49
00時20分01秒 0.01 15.53
00時30分01秒 0.01 15.56
00時40分01秒 0.01 15.65
00時50分01秒 0.04 15.87

04時10分01秒 0.01 15.60
04時20分01秒 0.01 15.73
04時30分01秒 0.01 15.53
04時40分01秒 0.40 17.58
04時50分01秒 0.03 15.94
05時00分01秒 0.01 15.67

19時10分01秒 0.01 15.68
19時20分01秒 0.01 15.53
19時30分01秒 0.01 15.44
19時40分01秒 0.04 16.49
19時50分01秒 0.14 36.60
20時00分01秒 0.01 16.36
20時10分01秒 0.03 16.35

00時00分01秒 DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util

01時20分01秒 dev252-0 0.10 0.00 0.87 9.12 0.00 1.18 0.89 0.01
01時30分01秒 dev252-0 0.10 0.00 0.89 9.08 0.00 1.02 0.76 0.01

04時00分01秒 dev252-0 0.11 0.00 1.04 9.75 0.00 0.62 0.59 0.01
04時10分01秒 dev252-0 0.10 0.00 1.06 10.19 0.00 0.73 0.68 0.01
04時20分01秒 dev252-0 0.09 0.00 0.81 9.04 0.00 0.80 0.72 0.01
04時30分01秒 dev252-0 0.09 0.00 0.77 8.75 0.00 0.81 0.72 0.01
04時40分01秒 dev252-0 0.31 0.00 **18.23 59.67 ** 0.00 1.25 0.29 0.01
04時50分01秒 dev252-0 0.13 0.00 1.31 10.18 0.00 0.92 0.75 0.01
05時00分01秒 dev252-0 0.14 0.00 1.50 10.42 0.00 0.80 0.57 0.01
05時10分01秒 dev252-0 0.13 0.00 1.28 10.11 0.00 0.99 0.68 0.01
05時20分01秒

19時00分01秒 dev252-0 0.12 0.00 1.34 11.11 0.00 0.94 0.69 0.01
19時10分01秒 dev252-0 0.11 0.00 1.00 9.09 0.00 1.26 0.88 0.01
19時20分01秒 dev252-0 0.09 0.00 0.84 9.16 0.00 1.15 0.85 0.01
19時30分01秒 dev252-0 0.09 0.00 0.83 9.02 0.00 1.36 0.89 0.01
19時40分01秒 dev252-0 0.14 0.00 1.36 9.83 0.00 0.92 0.59 0.01
19時50分01秒 dev252-0 1.64 3.67  187.16 116.59 0.02 9.55 0.37 0.06
20時00分01秒 dev252-0 0.11 0.00 1.07 10.00 0.00 0.92 0.75 0.01

--- /var/log/sar/sa09

00時00分01秒 proc/s cswch/s
00時10分01秒 0.02 16.91
00時20分01秒 0.01 16.44
00時30分01秒 0.02 16.94
00時40分01秒 0.01 16.56

04時20分01秒 0.01 18.51
04時30分01秒 0.01 16.57
04時40分02秒 0.01 16.63
04時50分01秒 0.50 55.70
05時00分01秒 0.01 16.22
05時10分01秒 0.01 16.56

00時00分01秒 DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util
00時50分01秒 dev252-0 0.13 0.59 1.01 12.80 0.00 0.85 0.65 0.01
01時00分01秒 dev252-0 0.08 0.00 0.76 9.12 0.00 0.98 0.74 0.01

04時00分01秒 dev252-0 0.09 0.00 0.84 9.16 0.00 0.89 0.64 0.01
04時10分01秒 dev252-0 0.09 0.00 0.75 8.62 0.00 1.29 0.83 0.01
04時20分01秒 dev252-0 0.18 0.00 2.42 13.41 0.00 0.73 0.44 0.01
04時30分01秒 dev252-0 0.09 0.00 0.77 8.75 0.00 0.98 0.72 0.01
04時40分02秒 dev252-0 0.09 0.00 0.81 9.04 0.00 1.07 0.81 0.01
04時50分01秒 dev252-0 12.71 207.21 25.53 18.31 0.01 0.70 0.37 0.47
05時00分01秒 dev252-0 0.10 0.00 0.93 9.33 0.00 1.02 0.77 0.01

--- /var/log/cron

Apr 8 04:34:01 ik1-331-25789 run-parts(/etc/cron.daily)[32120]: starting makewhatis.cron
Apr 8 04:34:02 ik1-331-25789 run-parts(/etc/cron.daily)[32280]: finished makewhatis.cron
Apr 8 04:34:02 ik1-331-25789 run-parts(/etc/cron.daily)[32120]: starting mlocate.cron
Apr 8 04:34:02 ik1-331-25789 run-parts(/etc/cron.daily)[32291]: finished mlocate.cron
Apr 8 04:34:02 ik1-331-25789 run-parts(/etc/cron.daily)[32120]: starting prelink
Apr 8 04:34:02 ik1-331-25789 run-parts(/etc/cron.daily)[32303]: finished prelink
Apr 8 04:34:02 ik1-331-25789 run-parts(/etc/cron.daily)[32120]: starting readahead.cron
Apr 8 04:34:02 ik1-331-25789 run-parts(/etc/cron.daily)[32315]: finished readahead.cron
Apr 8 04:34:02 ik1-331-25789 run-parts(/etc/cron.daily)[32120]: starting tmpwatch
Apr 8 04:34:02 ik1-331-25789 run-parts(/etc/cron.daily)[32353]: finished tmpwatch
Apr 8 04:34:02 ik1-331-25789 anacron[31999]: Job cron.daily' terminated Apr 8 04:34:02 ik1-331-25789 anacron[31999]: Normal exit (1 job run) Apr 8 04:40:01 ik1-331-25789 CROND[32355]: (root) CMD (/usr/lib64/sa/sa1 1 1) Apr 8 04:43:01 ik1-331-25789 CROND[32361]: (root) CMD (run-parts /etc/cron.hourly) Apr 8 04:43:01 ik1-331-25789 run-parts(/etc/cron.hourly)[32361]: starting 0anacron Apr 8 04:43:01 ik1-331-25789 run-parts(/etc/cron.hourly)[32370]: finished 0anacron Apr 8 04:50:01 ik1-331-25789 CROND[32372]: (root) CMD (/usr/lib64/sa/sa1 1 1) 〜 Apr 8 19:40:01 ik1-331-25789 CROND[455]: (root) CMD (/usr/lib64/sa/sa1 1 1) Apr 8 19:43:01 ik1-331-25789 CROND[528]: (root) CMD (run-parts /etc/cron.hourly) Apr 8 19:43:01 ik1-331-25789 run-parts(/etc/cron.hourly)[528]: starting 0anacron Apr 8 19:43:01 ik1-331-25789 run-parts(/etc/cron.hourly)[537]: finished 0anacron Apr 8 19:50:01 ik1-331-25789 CROND[540]: (root) CMD (/usr/lib64/sa/sa1 1 1) Apr 8 20:00:01 ik1-331-25789 CROND[546]: (root) CMD (/usr/lib64/sa/sa1 1 1) Apr 8 20:10:01 ik1-331-25789 CROND[566]: (root) CMD (/usr/lib64/sa/sa1 1 1) 〜 Apr 9 04:43:01 ik1-331-25789 anacron[1834]: Anacron started on 2019-04-09 Apr 9 04:43:01 ik1-331-25789 anacron[1834]: Job cron.daily' locked by another anacron - skipping
Apr 9 04:43:01 ik1-331-25789 anacron[1834]: Normal exit (0 jobs run)
Apr 9 04:43:01 ik1-331-25789 run-parts(/etc/cron.hourly)[1836]: finished 0anacron
Apr 9 04:48:01 ik1-331-25789 anacron[1666]: Job `cron.daily' started
Apr 9 04:48:01 ik1-331-25789 run-parts(/etc/cron.daily)[1838]: starting logrotate
Apr 9 04:48:01 ik1-331-25789 run-parts(/etc/cron.daily)[1847]: finished logrotate
Apr 9 04:48:01 ik1-331-25789 run-parts(/etc/cron.daily)[1838]: starting makewhatis.cron
Apr 9 04:48:01 ik1-331-25789 run-parts(/etc/cron.daily)[2002]: finished makewhatis.cron
Apr 9 04:48:01 ik1-331-25789 run-parts(/etc/cron.daily)[1838]: starting mlocate.cron
Apr 9 04:48:03 ik1-331-25789 run-parts(/etc/cron.daily)[2013]: finished mlocate.cron
Apr 9 04:48:03 ik1-331-25789 run-parts(/etc/cron.daily)[1838]: starting prelink
Apr 9 04:48:04 ik1-331-25789 run-parts(/etc/cron.daily)[2069]: finished prelink
Apr 9 04:48:04 ik1-331-25789 run-parts(/etc/cron.daily)[1838]: starting readahead.cron
Apr 9 04:48:04 ik1-331-25789 run-parts(/etc/cron.daily)[2081]: finished readahead.cron
Apr 9 04:48:04 ik1-331-25789 run-parts(/etc/cron.daily)[1838]: starting tmpwatch
Apr 9 04:48:04 ik1-331-25789 run-parts(/etc/cron.daily)[2119]: finished tmpwatch

### 補足情報(FW/ツールのバージョンなど) 使用OSバージョン:CentOS release 6.9 (Final)

良い質問の評価を上げる

以下のような質問は評価を上げましょう

  • 質問内容が明確
  • 自分も答えを知りたい
  • 質問者以外のユーザにも役立つ

評価が高い質問は、TOPページの「注目」タブのフィードに表示されやすくなります。

気になる質問をクリップする

クリップした質問は、後からいつでもマイページで確認できます。

またクリップした質問に回答があった際、通知やメールを受け取ることができます。

teratailでは下記のような質問を「具体的に困っていることがない質問」、「サイトポリシーに違反する質問」と定義し、推奨していません。

  • プログラミングに関係のない質問
  • やってほしいことだけを記載した丸投げの質問
  • 問題・課題が含まれていない質問
  • 意図的に内容が抹消された質問
  • 過去に投稿した質問と同じ内容の質問
  • 広告と受け取られるような投稿

評価を下げると、トップページの「アクティブ」「注目」タブのフィードに表示されにくくなります。

cateye
cateye

2019/04/08 11:52 編集

情報が少なすぎるようですが、swapはどうですか?
kenji267
kenji267

2019/04/08 12:04

vmstatでioが発生しているときのswapを確認してみましたが発生していないようです。
k-nishiyama
k-nishiyama

2019/04/09 00:44 編集

朝4時台に秒間10kBって、ただのログローテでは・・・?
kenji267
kenji267

2019/04/09 12:23

そういえばこの時間はログローテなんでしょうね。 この時に発生しているログってあるんでしょうか?
kenji267
kenji267

2019/04/09 12:25

あとDISK I/Oが発生している時点から、合理的に何が発生しているのか調査する方法を知りたいです。 今ですと推測の状況です。
kenji267
kenji267

2019/04/09 12:37

朝4時のログローテの件ですが、この時のメモリがどうなっているかがわかるログってありますでしょうか?
k-nishiyama
k-nishiyama

2019/04/10 04:47

> ログローテのログ cronのログファイルに記述されていると思いますよ > ログローテ実行時のメモリ利用状況 sarがインストールされているならば確認できますよ

まだ回答がついていません

会員登録して回答してみよう

15分調べてもわからないことは
teratailで質問しよう!

ただいまの回答率
87.20%

質問をまとめることで
思考を整理して素早く解決

テンプレート機能で
簡単に質問をまとめる

質問する

関連した質問

同じタグがついた質問を見る

CentOS

CentOSは、主にRed Hat Enterprise Linux(RHEL)をベースにした、フリーのソフトウェアオペレーティングシステムです。

Linux

Linuxは、Unixをベースにして開発されたオペレーティングシステムです。日本では「リナックス」と呼ばれています。 主にWebサーバやDNSサーバ、イントラネットなどのサーバ用OSとして利用されています。 上位500のスーパーコンピュータの90%以上はLinuxを使用しています。 携帯端末用のプラットフォームAndroidは、Linuxカーネル上に構築されています。