I'm trying to add my esxi servers (I have 3 of them) to my nagios monitoring. I'm using the perl SDK and script as documented in various places on the internet, the latest script is here: http://git.op5.org/git/?p=nagios/op5plugins.git;a=blob_plain;f=check_esx3.pl;hb=HEAD
I have updated my two esxi4 boxes to 4.1u1 (4.1.0, 348481)
The problem I'm experiencing is that the checks are very slow.
I've traced the perl command using DProf
/usr/bin/perl -d:DProf /usr/lib/nagios/plugins/check_esxi -H HOSTNAME -u nagios -p PASSWORD -l cpu -s usage -w 85 -c 95
and I get the following output (via dproff)
Total Elapsed Time = 6.634312 Seconds User+System Time = 5.154312 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 44.1 2.276 4.339 2 1.1380 2.1695 Vim::login 12.9 0.667 1.638 4254 0.0002 0.0004 Class::MethodMaker::Engine::create_methods 8.91 0.459 0.588 4254 0.0001 0.0001 Class::MethodMaker::scalar::scal0000 5.18 0.267 0.304 4254 0.0001 0.0001 Class::MethodMaker::Engine::install_methods 3.20 0.165 0.165 26005 0.0000 0.0000 XML::LibXML::Node::nodeName 2.50 0.129 0.129 4254 0.0000 0.0000 Class::MethodMaker::Engine::check_opts 2.41 0.124 0.594 925 0.0001 0.0006 ComplexType::deserialize 1.92 0.099 0.091 1561 0.0001 0.0001 Class::MethodMaker::Engine::_find_target_class 1.40 0.072 0.072 3326 0.0000 0.0000 XML::LibXML::Node::textContent 1.36 0.070 0.336 5816 0.0000 0.0001 XML::LibXML::Element::getChildrenByTagName 1.14 0.059 0.068 4254 0.0000 0.0000 Class::MethodMaker::OptExt::encode 1.07 0.055 0.055 5816 0.0000 0.0000 XML::LibXML::Node::_childNodes 1.05 0.054 1.820 1561 0.0000 0.0012 Class::MethodMaker::Engine::import 0.97 0.050 0.050 1 0.0500 0.0500 utf8::AUTOLOAD 0.97 0.050 0.205 25 0.0020 0.0082 main::BEGIN
As I'm running 4.1, I've enabled SSH and connected to the console. This is what I see in /var/log/messages (this is esxi4 so there's no vkernel log)
[2011-09-05 22:53:36.543 51E40B90 verbose 'Proxysvc Req06598'] New proxy client SSL(TCP(local=192.168.99.101:57617, peer=192.168.99.22:443)) [2011-09-05 22:53:43.091 52081B90 verbose 'Proxysvc Req06599'] New proxy client SSL(TCP(local=192.168.99.101:57652, peer=192.168.99.22:443)) [2011-09-05 22:53:43.136 51E81B90 info 'Vimsvc'] [Auth]: User nagios [2011-09-05 22:53:43.137 51E81B90 info 'ha-eventmgr'] Event 4814 : User firstname.lastname@example.org logged in [2011-09-05 22:53:44.429 52081B90 verbose 'App'] CloseSession called for session id=5260ca10-fdc9-3a26-4d0c-45be7792c716 [2011-09-05 22:53:44.430 52081B90 info 'ha-eventmgr'] Event 4815 : User nagios logged out
Notice the two logins, seperated by approximately 7 seconds - with the second completing the check quickly.
As an aside, i'm also seeing two of these regularly in the log, but I think it's unrelated
[2011-09-05 22:53:40.031 51AD1B90 verbose 'Statssvc'] HostCtl exception Unable to complete Sysinfo operation. Please see the VMkernel log file for more details.
I also notice login in to the server via vsphere is reasonably slow, also about 3-4 seconds before it starts loading. This could be unrelated. The esxi server isn't under huge load, though it has iscsi luns mounted and maybe about 6-7 active VMs. I've checked (and increased) the resource allocation for the host and also checked esxtop (with no findings) while running the check command.
This delay is an issue, because the perl processes from nagios run at 100% cpu while they're trying to connect, and it's happening on all 3 of my esxi servers. So as nagios issues more and more checks, the monitoring server CPU and load averages go through the roof as all of the processes are waiting for responses. This only serves to exasperate the delay issue and cause all of the checks to time out.
A friend, also running nagios, the same monitoring script and the same esxi update can run the same check and it completes in less than a second, whereas for me it takes up to 10 seconds (as you can see in the dproff output)
Please let me know if there is any additional information I can provide to help diagnose this issue The hosts were rebooted (with the 4.1 update) last night
Thanks in advance,
--edit1: added total times to proff output and made perl check command a block quote
I have been actively diagnosing this since posting. I have found that my friends nagios server is an x64 machine, so I stood up a new ubuntu 10.4 x64 VM (on a different host mind you) After installing all the stuff needed for the esxi checks (lots of cpan modules were required) I can time the checks on that new install and a CPU check completes in around 2 seconds.
This indicates the issue lies with the nagios server or perl, not with the VMWare esxi server(s)
I've made sure that
- vmware tools are installed
- all the cpan modules I had to install on the test server are up to date on the production server
- the production server is aptitude update && aptitude upgrade 'd
- reverse DNS (as per below) is working
- forward DNs (as per below) is working
- tested with direct IP, no hostame
- Stopped the nagios server so the LA drops down to 0.01 before doing my tests
- Changed the vmware nic driver from flexible (host is esxi3.5) to an enhanced vmxnet
- Increased the virtual cpu count from 1 to 2
I can't migrate nagios to the new x64 machine, it doesn't run on our management vm server (which contains this monitoring box plus a few jumphosts)
The 32bit box (that I originaly started with and profiled above) is still taking 8-10 seconds of 100% CPU to complete a CPU check
I realised the disk is a virtual disk mounted on an iSCSI lun for this server and that slows the disk IO down somewhat but I wouldn't expect querying a remote server to be a high disk IO operation.