vcsimの小ネタ: デバッグ情報を確認する

久しぶりにvcsimの小ネタを投稿します。

TL; DR

• https://${vcsimのURL}/debug/vars でvcsimのデバッグ情報が得られる！
  • json形式
  • expvar使用
  • 内容: https://github.com/vmware/govmomi/blob/a2241de746f8d97ac7ef4102babe6c0c3cbe39e2/vcsim/main.go#L202

はじめに

vcsimの実装を読んでいると、/debug/vars のエンドポイントで待ち受けている処理を見つけました。
調べてみるとどうやらデバッグ情報が取得できるよう¹なので、取れた情報について紹介したいと思います。

バージョン

• vcsim 0.29.0 (執筆時点の最新)

デバッグ情報へリクエスト

https://${vcsimのURL}/debug/vars で、JSON形式で取得できます。vCenterの機能ではないため、govc ではなく直接 curl でリクエストします。

# いつも通りvcsimを起動
$ vcsim

$ curl -sk https://localhost:8989/debug/vars
{
"cmdline": ["vcsim"],
"memstats": {"Alloc":2489632,"TotalAlloc":8662600,"Sys":19090192,"Lookups":0,"Mallocs":123918,"Frees":109511,"HeapAlloc":2489632,"HeapSys":11927552,"HeapIdle":6389760,"HeapInuse":5537792,"HeapReleased":5873664,"HeapObjects":14407,"StackInuse":655360,"StackSys":655360,"MSpanInuse":121176,"MSpanSys":130560,"MCacheInuse":19200,"MCacheSys":31200,"BuckHashSys":14776,"GCSys":4960592,"OtherSys":1370152,"NextGC":5804816,"LastGC":1662591561555264494,"PauseTotalNs":468843,"PauseNs":[38404,30990,92427,173324,133698,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"PauseEnd":[1662591271239359290,1662591271363068484,1662591271569975490,1662591440552870270,1662591561555264494,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"NumGC":5,"NumForcedGC":0,"GCCPUFraction":0.0000030617654215572535,"EnableGC":true,"DebugGC":false,"BySize":[{"Size":0,"Mallocs":0,"Frees":0},{"Size":8,"Mallocs":729,"Frees":431},{"Size":16,"Mallocs":27897,"Frees":21863},{"Size":24,"Mallocs":12288,"Frees":10434},{"Size":32,"Mallocs":22426,"Frees":20992},{"Size":48,"Mallocs":8792,"Frees":7169},{"Size":64,"Mallocs":24221,"Frees":23354},{"Size":80,"Mallocs":710,"Frees":564},{"Size":96,"Mallocs":1610,"Frees":1332},{"Size":112,"Mallocs":427,"Frees":262},{"Size":128,"Mallocs":517,"Frees":299},{"Size":144,"Mallocs":4437,"Frees":4380},{"Size":160,"Mallocs":175,"Frees":76},{"Size":176,"Mallocs":195,"Frees":119},{"Size":192,"Mallocs":77,"Frees":49},{"Size":208,"Mallocs":308,"Frees":251},{"Size":224,"Mallocs":116,"Frees":16},{"Size":240,"Mallocs":42,"Frees":24},{"Size":256,"Mallocs":54,"Frees":28},{"Size":288,"Mallocs":427,"Frees":399},{"Size":320,"Mallocs":265,"Frees":250},{"Size":352,"Mallocs":174,"Frees":108},{"Size":384,"Mallocs":38,"Frees":24},{"Size":416,"Mallocs":143,"Frees":31},{"Size":448,"Mallocs":23,"Frees":8},{"Size":480,"Mallocs":11,"Frees":8},{"Size":512,"Mallocs":19,"Frees":13},{"Size":576,"Mallocs":34,"Frees":21},{"Size":640,"Mallocs":20,"Frees":5},{"Size":704,"Mallocs":79,"Frees":47},{"Size":768,"Mallocs":35,"Frees":19},{"Size":896,"Mallocs":557,"Frees":23},{"Size":1024,"Mallocs":32,"Frees":11},{"Size":1152,"Mallocs":21,"Frees":14},{"Size":1280,"Mallocs":10,"Frees":5},{"Size":1408,"Mallocs":54,"Frees":20},{"Size":1536,"Mallocs":6,"Frees":5},{"Size":1792,"Mallocs":18,"Frees":7},{"Size":2048,"Mallocs":38,"Frees":26},{"Size":2304,"Mallocs":12,"Frees":4},{"Size":2688,"Mallocs":11,"Frees":5},{"Size":3072,"Mallocs":11,"Frees":5},{"Size":3200,"Mallocs":3,"Frees":1},{"Size":3456,"Mallocs":0,"Frees":0},{"Size":4096,"Mallocs":40,"Frees":30},{"Size":4864,"Mallocs":4,"Frees":3},{"Size":5376,"Mallocs":1,"Frees":0},{"Size":6144,"Mallocs":11,"Frees":3},{"Size":6528,"Mallocs":0,"Frees":0},{"Size":6784,"Mallocs":0,"Frees":0},{"Size":6912,"Mallocs":1,"Frees":1},{"Size":8192,"Mallocs":5,"Frees":3},{"Size":9472,"Mallocs":19,"Frees":2},{"Size":9728,"Mallocs":0,"Frees":0},{"Size":10240,"Mallocs":1,"Frees":0},{"Size":10880,"Mallocs":4,"Frees":4},{"Size":12288,"Mallocs":6,"Frees":6},{"Size":13568,"Mallocs":0,"Frees":0},{"Size":14336,"Mallocs":1,"Frees":0},{"Size":16384,"Mallocs":0,"Frees":0},{"Size":18432,"Mallocs":1,"Frees":0}]},
"vcsim": {"Registry":{"Objects":111,"Locks":48},"Model":{"Datacenter":1,"Portgroup":2,"PortgroupNSX":0,"OpaqueNetwork":0,"Host":4,"Cluster":1,"Pool":2,"Datastore":1,"Machine":4,"Folder":5,"App":0,"Pod":0}}
}

実装を見ると、 expvars パッケージを使っていました。このパッケージはそのものズバリ、 /debug/vars のエンドポイントでデバッグ情報を返せるようにするものです。

実装

取れる内容

大きく分けて以下の3種類です。

フィールド名	内容
memstats	メモリ使用量
cmdline	vcsim起動時のコマンドライン引数
vcsim	vcsim固有の情報

expvars由来の情報

上記のうち memstats と cmdline は expvars にデフォルトで入っています（リファレンス）。

memstats: メモリ使用量

メモリ関連の統計情報が取れます。中身は runtime.Memstats です。

例：ヒープ使用量取得

# 単位はByte
$ curl -sk https://localhost:8989/debug/vars | jq .memstats.HeapAlloc
2496904

どうやら2.5MB使っているようです。

vm100個で起動すると11MBに増えました。当たり前ですがリソースが多いほどメモリを食います。

$ vcsim -vm 100

$ curl -sk https://localhost:8989/debug/vars | jq .memstats.HeapAlloc
10007664

メモリ使用量のほかに、GCのタイミングも確認できます。

# 前回のGC実行（UNIX epochから経過したナノ秒形式）
$ curl -sk https://localhost:8989/debug/vars | jq '.memstats.LastGC'
1662593227822978800
# jqで整形
$ curl -sk https://localhost:8989/debug/vars | jq '.memstats.LastGC | ./1e9 | todate'
"2022-09-07T23:24:30Z"

cmdline: コマンドライン引数

vcsimを起動した際のコマンドライン引数が取得できます。

$ vcsim

$ curl -sk https://localhost:8989/debug/vars | jq .cmdline
[
  "vcsim"
]

オプション指定した場合

$ vcsim -vm 10

$ curl -sk https://localhost:8989/debug/vars | jq .cmdline
[
  "vcsim",
  "-vm",
  "10"
]

vcsim: vcsim固有の情報

vcsim固有の情報、具体的には各種ManagedObjectがいくつあるかを取得できます。

# Registry.Objectsが合計、主要object各種の個数はModel
$ curl -sk https://localhost:8989/debug/vars | jq .vcsim
{
  "Registry": {
    "Objects": 111,
    "Locks": 48
  },
  "Model": {
    "Datacenter": 1,
    "Portgroup": 2,
    "PortgroupNSX": 0,
    "OpaqueNetwork": 0,
    "Host": 4,
    "Cluster": 1,
    "Pool": 2,
    "Datastore": 1,
    "Machine": 4,
    "Folder": 5,
    "App": 0,
    "Pod": 0
  }
}

試しにvmを1つ消すと、Machine が4から3に減りました。

$ govc vm.destroy DC0_H0_VM0
$ curl -sk https://localhost:8989/debug/vars | jq .vcsim
{
  "Registry": {
    "Objects": 114,
    "Locks": 53
  },
  "Model": {
    "Datacenter": 1,
    "Portgroup": 2,
    "PortgroupNSX": 0,
    "OpaqueNetwork": 0,
    "Host": 4,
    "Cluster": 1,
    "Pool": 2,
    "Datastore": 1,
    "Machine": 3,
    "Folder": 5,
    "App": 0,
    "Pod": 0
  }
}

RegistryのObjectsは3つ増えていますが、これはvm削除の際にタスクが4つ発行されたからだと思われます。

$ govc tasks
...
PowerOff                                 vm-55                          vcsim                           08:40:56  08:40:56  08:40:56 success [604.927µs]
VirtualMachine.Destroy                   vm-55                          vcsim                           08:40:56  08:40:56  08:40:56 success [10.602199ms]
DeleteVirtualDisk                        virtualDiskManager             vcsim                           08:40:56  08:40:56  08:40:56 success [80.565µs]
DeleteDatastoreFile                      FileManager                    vcsim                           08:40:56  08:40:56  08:40:56 success [201.519µs]

おわりに

以上、vcsimのデバッグ機能についても紹介でした。正直使う機会はほぼ無いと思いますが Goのexpvarsの仕組みも知ることができたので、ツールを自作する際に参考にできそうです。

1. READMEに説明が無いので、おそらくvcsim自体の開発での内部利用向けだと思います。 ↩