我在全新硬件(Atom C2750、16GB RAM)上安装了 ESXi 6.0 Update 1(Build 3029758)。
VM 是 Solaris 11.0,具有 1 个 vCPU 和 4GB RAM。Solaris 是从 sol-11-1111-text-x86.iso 安装的,除了安装 VMware Tools 外,没有进行任何其他配置。
启动虚拟机后,主机 CPU 显示空闲(12MHz),但它每天缓慢上升约 10%(每天 240MHz),直到达到 95% 左右,此时虚拟机本身变得无响应,但 ESXi 仍然显示虚拟机运行良好。
在每个阶段,虚拟机本身总是报告它处于空闲状态。重新启动虚拟机会使主机 CPU 重新处于空闲状态(12MHz),然后缓慢攀升。
虚拟机正常运行时间:
# uptime
00:06am up 4 days 0:12, 1 user, load average: 0.00, 0.00, 0.00
esxtop 的输出:
1:10:11pm up 4 days 47 min, 504 worlds, 2 VMs, 2 vCPUs; CPU load average: 0.06, 0.06, 0.06
PCPU USED(%): 5.3 0.5 0.1 0.1 0.1 45 0.1 0.2 AVG: 6.5
PCPU UTIL(%): 5.0 0.5 0.2 0.5 0.0 42 0.1 0.4 AVG: 6.2
ID GID NAME NWLD %USED %RUN %SYS %WAIT %VMWAIT %RDY %IDLE %OVRLP %CSTP %MLMTD %SWPWT
36739 27266 vmx 1 0.03 0.02 0.01 99.98 - 0.00 0.00 0.00 0.00 0.00 0.00
36741 27266 vmast.36740 1 0.14 0.13 0.00 99.87 - 0.01 0.00 0.00 0.00 0.00 0.00
36742 27266 vmx-vthread-5 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36743 27266 vmx-vthread-6:n 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36744 27266 vmx-vthread-7:n 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36745 27266 vmx-vthread-8:n 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36746 27266 vmx-mks:nas 1 0.01 0.01 0.00 99.99 - 0.00 0.00 0.00 0.00 0.00 0.00
36747 27266 vmx-svga:nas 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36748 27266 vmx-vcpu-0:nas 1 45.15 42.35 0.00 57.66 0.02 0.00 57.63 0.03 0.00 0.00 0.00
如果有人想知道,我使用的是 Solaris 11.0,因为此 VM 的目的是使用带有物理 RDM 的 ZFS 来创建 NAS。不幸的是,Solaris 11.1(及更高版本)+ 物理 RDM = ESXi 紫屏(请参阅错误报告:Solaris 11.1 + RDM = ESXi 5.1 紫屏)。此问题本应在 ESXi 5.5 中得到修复,但在 ESXi 6.0U1 中仍然存在。我已测试 (ESXi 6.0U1 + Solaris 11.1 + 物理 RDM) 和 (ESXi 6.0U1 + Solaris 11.3 + 物理 RDM)。这两种组合都会导致紫屏。
不过有趣的是,没有物理 RDM 的 Solaris 11.1(及更高版本)不会受到上述主机 CPU 使用率缓慢攀升的影响。因此,我要么必须处理奇怪的主机 CPU 攀升,要么必须处理紫色屏幕 :-(
Andrew Henle 要求提供附加信息(2016-01-11)
esxtop 的输出现在为:
11:12:46am up 5 days 22:49, 518 worlds, 3 VMs, 3 vCPUs; CPU load average: 0.09, 0.08, 0.08
PCPU USED(%): 1.3 5.9 0.6 0.6 0.4 63 0.3 0.2 AVG: 9.1
PCPU UTIL(%): 1.3 5.6 0.5 0.8 0.7 59 0.4 0.1 AVG: 8.6
ID GID NAME NWLD %USED %RUN %SYS %WAIT %VMWAIT %RDY %IDLE %OVRLP %CSTP %MLMTD %SWPWT
36739 27266 vmx 1 0.03 0.02 0.01 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36741 27266 vmast.36740 1 0.14 0.13 0.00 100.00 - 0.01 0.00 0.00 0.00 0.00 0.00
36742 27266 vmx-vthread-5 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36743 27266 vmx-vthread-6:n 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36744 27266 vmx-vthread-7:n 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36745 27266 vmx-vthread-8:n 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36746 27266 vmx-mks:nas 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36747 27266 vmx-svga:nas 1 0.00 0.00 0.00 100.00 - 0.00 0.00 0.00 0.00 0.00 0.00
36748 27266 vmx-vcpu-0:nas 1 64.28 59.40 0.00 40.69 0.05 0.04 40.64 0.03 0.00 0.00 0.00
VM 正常运行时间现为:
# uptime
22:14pm up 5 days 22:21, 1 user, load average: 0.00, 0.00, 0.00
虚拟机 prstat 输出:
# prstat -a -n 20
PID USERNAME SIZE RSS STATE PRI NICE TIME CPU PROCESS/NLWP
702 root 19M 9904K sleep 59 0 0:15:33 0.3% vmtoolsd/2
3272 root 11M 3508K cpu0 59 0 0:00:00 0.1% prstat/1
5 root 0K 0K sleep 99 -20 0:00:05 0.1% zpool-rpool/136
3237 root 18M 5172K sleep 59 0 0:00:00 0.1% sshd/1
427 root 7668K 5768K sleep 59 0 0:00:17 0.0% hald/4
369 root 12M 3552K sleep 59 0 0:00:14 0.0% nscd/35
602 root 35M 16M sleep 59 0 0:00:26 0.0% fmd/28
3238 root 11M 3344K sleep 59 0 0:00:00 0.0% bash/1
292 root 3220K 1376K sleep 59 0 0:00:00 0.0% vbiosd/3
247 root 2648K 1316K sleep 60 -20 0:00:00 0.0% zonestatd/5
267 root 11M 1272K sleep 59 0 0:00:00 0.0% net-physical/1
81 daemon 14M 4612K sleep 59 0 0:00:00 0.0% kcfd/3
975 root 3680K 2240K sleep 59 0 0:00:00 0.0% nmz/1
108 root 13M 2552K sleep 59 0 0:00:00 0.0% syseventd/18
48 root 3880K 2256K sleep 59 0 0:00:04 0.0% dlmgmtd/7
162 netadm 4100K 2476K sleep 59 0 0:00:00 0.0% ipmgmtd/5
39 netcfg 3784K 2424K sleep 59 0 0:00:04 0.0% netcfgd/4
335 root 11M 2848K sleep 59 0 0:00:00 0.0% picld/4
13 root 19M 18M sleep 59 0 0:00:29 0.0% svc.configd/22
11 root 20M 11M sleep 59 0 0:00:07 0.0% svc.startd/12
NPROC USERNAME SWAP RSS MEMORY TIME CPU
53 root 444M 173M 4.2% 0:18:11 0.6%
1 smmsp 6288K 1584K 0.0% 0:00:00 0.0%
2 daemon 17M 5664K 0.1% 0:00:00 0.0%
1 netadm 4100K 2476K 0.1% 0:00:00 0.0%
1 netcfg 3784K 2424K 0.1% 0:00:04 0.0%
Total: 60 processes, 637 lwps, load averages: 0.01, 0.00, 0.00
虚拟机内存使用情况:
# echo ::memstat | mdb -k
Page Summary Pages MB %Tot
------------ ---------------- ---------------- ----
Kernel 101923 398 10%
ZFS File Data 60118 234 6%
Anon 30785 120 3%
Exec and libs 2168 8 0%
Page cache 5295 20 1%
Free (cachelist) 8599 33 1%
Free (freelist) 837526 3271 80%
Total 1046414 4087
Physical 1046413 4087
Andrew Henle 要求提供附加信息(2016-01-13)
vmtoolsd
是 Solaris 的 VMware Tools 守护进程。该进程不是原因。在调查时,我在虚拟机上停止了该进程,发现没有什么变化。
是的,所有数据都是同时采集的。而且,它确实显示虚拟机 CPU 使用率非常低,但主机 CPU 使用率非常高。
您建议的使用mpstat
(我认为)是正确的。它揭示了虚拟机上大量的中断。
# mpstat 2
CPU minf mjf xcal intr ithr csw icsw migr smtx srw syscl usr sys wt idl
0 0 0 0 60208 107 147 1 0 1 0 100 0 14 0 86
0 0 0 0 130658 103 181 4 0 1 0 413 1 28 0 72
0 0 0 0 130157 103 134 1 0 0 0 39 0 26 0 74
0 0 0 0 129690 104 134 1 0 1 0 46 0 27 0 73
0 0 0 0 129722 102 142 1 0 1 0 42 0 27 0 73
然后我使用intrstat
虚拟机来查看引发了哪些中断,但没有发现任何有用的信息。
# intrstat
device | cpu0 %tim
-------------+---------------
ata#1 | 0 0.0
e1000g#0 | 0 0.0
device | cpu0 %tim
-------------+---------------
ata#1 | 0 0.0
e1000g#0 | 9 0.0
device | cpu0 %tim
-------------+---------------
ata#1 | 0 0.0
e1000g#0 | 2 0.0
然后,我使用了一个多年来一直使用的旧 dtrace 脚本来仔细查看虚拟机上的中断。它似乎表明中断是由cbe_fire然而我并不真正知道那是什么并且也找不到任何有用的信息。
# ./intrstat.d
dtrace: script './intrstat.d' matched 4 probes
dtrace: 24610 dynamic variable drops with non-empty dirty list
CPU ID FUNCTION:NAME
0 62167 :tick-1sec
driver instance intr-count
---------------------------------------
ata 0x1 0
mpt 0x0 0
mpt 0x2 0
e1000g 0x0 3
<unknown> unix`cbe_fire 71405
dtrace: 24005 dynamic variable drops with non-empty dirty list
0 62167 :tick-1sec
driver instance intr-count
---------------------------------------
ata 0x1 0
mpt 0x0 0
mpt 0x2 0
e1000g 0x0 3
<unknown> unix`cbe_fire 70285
dtrace: 23759 dynamic variable drops with non-empty dirty list
0 62167 :tick-1sec
driver instance intr-count
---------------------------------------
mpt 0x0 0
mpt 0x2 0
ata 0x1 1
e1000g 0x0 3
<unknown> unix`cbe_fire 71097
下面是完整的中断表。
# echo '::interrupts -d' | mdb -k
IRQ Vect IPL Bus Trg Type CPU Share APIC/INT# Driver Name(s)
1 0x41 5 ISA Edg Fixed 0 1 0x0/0x1 i8042#0
9 0x80 9 PCI Lvl Fixed 0 1 0x0/0x9 acpi_wrapper_isr
12 0x42 5 ISA Edg Fixed 0 1 0x0/0xc i8042#0
15 0x44 5 ISA Edg Fixed 0 1 0x0/0xf ata#1
16 0x43 5 PCI Lvl Fixed 0 1 0x0/0x10 mpt#1
17 0x40 5 PCI Lvl Fixed 0 2 0x0/0x11 mpt#2, mpt#0
18 0x60 6 PCI Lvl Fixed 0 1 0x0/0x12 e1000g#0
24 0x81 7 PCI Edg MSI 0 1 - pcieb#0
25 0x30 4 PCI Edg MSI 0 1 - pcieb#1
26 0x82 7 PCI Edg MSI 0 1 - pcieb#2
27 0x31 4 PCI Edg MSI 0 1 - pcieb#3
28 0x83 7 PCI Edg MSI 0 1 - pcieb#4
29 0x32 4 PCI Edg MSI 0 1 - pcieb#5
30 0x84 7 PCI Edg MSI 0 1 - pcieb#6
31 0x33 4 PCI Edg MSI 0 1 - pcieb#7
32 0x85 7 PCI Edg MSI 0 1 - pcieb#8
33 0x34 4 PCI Edg MSI 0 1 - pcieb#9
34 0x86 7 PCI Edg MSI 0 1 - pcieb#10
35 0x35 4 PCI Edg MSI 0 1 - pcieb#11
36 0x87 7 PCI Edg MSI 0 1 - pcieb#12
37 0x36 4 PCI Edg MSI 0 1 - pcieb#13
38 0x88 7 PCI Edg MSI 0 1 - pcieb#14
39 0x37 4 PCI Edg MSI 0 1 - pcieb#15
40 0x89 7 PCI Edg MSI 0 1 - pcieb#16
41 0x38 4 PCI Edg MSI 0 1 - pcieb#17
42 0x8a 7 PCI Edg MSI 0 1 - pcieb#18
43 0x39 4 PCI Edg MSI 0 1 - pcieb#19
44 0x8b 7 PCI Edg MSI 0 1 - pcieb#20
45 0x3a 4 PCI Edg MSI 0 1 - pcieb#21
46 0x8c 7 PCI Edg MSI 0 1 - pcieb#22
47 0x3b 4 PCI Edg MSI 0 1 - pcieb#23
48 0x8d 7 PCI Edg MSI 0 1 - pcieb#24
49 0x3c 4 PCI Edg MSI 0 1 - pcieb#25
50 0x8e 7 PCI Edg MSI 0 1 - pcieb#26
51 0x3d 4 PCI Edg MSI 0 1 - pcieb#27
52 0x8f 7 PCI Edg MSI 0 1 - pcieb#28
53 0x3e 4 PCI Edg MSI 0 1 - pcieb#29
208 0xd0 14 Edg IPI all 1 - kcpc_hw_overflow_intr
209 0xd1 14 Edg IPI all 1 - cbe_fire
240 0xe0 15 Edg IPI all 1 - apic_error_intr
我又陷入困境了 :(
Andrew Henle 要求提供附加信息(2016-01-15)
dtrace 脚本的输出结束:
unix`do_splx+0x97
genunix`disp_lock_exit+0x55
genunix`post_syscall+0x61a
unix`0xfffffffffb800cb7
18
unix`todpc_rtcget+0xe5
unix`todpc_get+0x1a
unix`tod_get+0x1a
genunix`clock+0xa53
genunix`cyclic_softint+0xd6
unix`cbe_softclock+0x1a
unix`av_dispatch_softvect+0x62
unix`dispatch_softint+0x33
unix`switch_sp_and_call+0x13
38
unix`sys_syscall+0xff
39
genunix`fsflush_do_pages+0x142
genunix`fsflush+0x3d4
unix`thread_start+0x8
58
unix`dispatch_softint+0x27
unix`switch_sp_and_call+0x13
26573
unix`mach_cpu_idle+0x6
unix`cpu_idle+0x150
unix`idle+0x58
unix`thread_start+0x8
135471
最后一个堆栈跟踪是空闲循环。计数为 26573 的倒数第二个堆栈跟踪似乎是罪魁祸首,但那里没有太多信息。
答案1
(将其作为答案发布以便可以格式化代码)
您可以以 root 身份运行此 dtrace 脚本,这样您就可以知道内核在哪里花费了它的时间:
#!/usr/sbin/dtrace -s
profile:::profile-1001hz
/arg0/
{
@[ stack() ] = count();
}
- 将其放入一个文件中,并命名为以下描述性名称
hotspot.d
chmod
使其可执行:chmod 755 hotspot.d
- 运行:
./hotspot.d
- 打印出有关匹配 N 个探测器的信息几秒钟后,点击 停止其运行
CTRL-C
。
您将看到大量数据 - 运行时采样的每个内核堆栈跟踪,按该堆栈跟踪的样本数增加排序。忽略堆栈idle
跟踪中某处的数据 - 即空闲循环 - 很可能最后几个非空闲堆栈跟踪就是您的系统花费所有时间的地方。