カテゴリー: 仮想化

投稿日:

Proxmox VE 3.1のリリースおよびソフトウェア更新に変更あり

うちの環境で使用しているProxmox Virtual Environment(Proxmox VE)に、最新版のProxmox VE 3.1が出た。
「Proxmox Virtual Environment 3.1 Released」

大きな変更点がある。

5月リリースのProxmox VE 3.0で、ベースOSがDebian 7.0 (Wheezy)に切り替わり、それに伴いいろんな変更があった。

今回のProxmox VE 3.1では、Release Historyでは記載されていないが、リリース告知では記載されている重大な変更点がある。

それは「Enterprise Repository」の開始である。

New Enterprise Repository
Proxmox Server Solutions – maintainer of the Proxmox VE repositories – introduces two new package repositories named “pve-enterprise” and “pve-no-subscription”. Beginning with Proxmox VE 3.1, the default repository is the Proxmox VE Enterprise repository. It allows secure access to stable updates, security patches and bug-fixes and is available to subscription users only. Proxmox VE users who do not want to use the subscription service can access the packages via the “pve-no-subscription” repository. These packages are not heavily tested, therefore the No-subscription repository is not recommended for production servers.

いままでは、サポートを買わなくても、ソフトウェア更新は普通にあるし、特に問題を感じなかったのですが、さすがにアレだったようで、「無償ユーザ向けソフトウェア更新(Proxmox VE No-Subscription Repository)」と「有償ユーザ向けソフトウェア更新(Proxmox VE Enterprise Repository)」に分割されました。

Proxmox Wiki「Package repositories」から実際のpve-no-subscriptionで配布されているソフトウェア一覧を見てみると、無償ユーザであっても基本的な機能は提供される模様。
有償ユーザ向けには、どのようなソフトウェアが配信されるのかは、特に記載が見当たらないというのが謎です・・・

有償ユーザには、どれくらいの金額からなれるのか確認してみると、「Subscription Plans」によれば、最低ラインは「Community Edition」で月額「1CPUあたり4.16ユーロ」とのこと。
この価格は、Proxmox VE 3.1リリースに合わせて半額以下になっています。（いままでは、月額「1CPUあたり9.90ユーロ」)

とりあえずは無償ユーザでProxmox VE 3.1へのアップデート実施かな・・・と

2013/09/05追記

「Details about the new pve-no-subscripton repository」

投稿日:

SSDを仮想環境のストレージキャッシュとして使うプロダクト(IBM,Fusion-IO,ProximalData,PernixData)

2021/04/07追記

Fusion IO → 2014年にSanDiskに買収。SanDisk Flashsoft(終了済)
ProximalData AutoCache → 2014年11月頃にSamsungに買収? Samsung ProximalData(終了済)
PernixData FVP→ 2016年にNutanixに買収された(2019年EoL)
OCZ → 2013年に東芝に買収されたあと、2019年に東芝メモリがKIOXIAになったが、移管されなかった?

また、VMware vSphere純正として登場したvFlash Read Cache。なんと、2019年にvSphere 6.7 Update 2で終息してしまった。vSANで分散ストレージ作ればいいでしょ、ということになったようだ。

では、2021年現在で提供されているESXiサーバ側でストレージキャッシュを持つような似たようなプロダクトとして何があるのか？

Virtunet Systems社「VirtuCache」で、ESXi 7.0U2のコンパチにも掲載されている

ぐらいしかないらしい。

サーバ本体に入れたPCIe接続のSSD(Fusion-IOなど)や、普通のSSDなどを、ストレージキャッシュとして使おうというソフトウェアをIBMが出してきた。

IBMプレスリリース:「仮想化環境の高速な処理を実現するFlashCache Storage Accelerator」
クラウドWatchでの紹介記事:「日本IBM、フラッシュメモリを用いて仮想環境での処理を高速化するキャッシュソフト」

これと類似のソフトウェアというのは、すでにいくつか製品がある。

・Fusion-IO ioTurbine
　これはFusion-IO専用
　高速化をはかれるストレージは「Designed for all major SAN and NAS storage systems」とあるので
　FC/SAS/iSCSI/NFSなのかな？と思われる。
　vSphere ESXi用にインストールして使う

・ProximalData AutoCache
　Fusion-IO,LSI Nytro WarpDriveなどのPCIe系や、普通のSSDに対応
　高速化をはかれるストレージは、FC/SAS/iSCSIハードウェアイニシエータ/iSCSIソフトウェアイニシエータ
　そして、NFS、と多岐に渡る。
　評価中だけど、特に問題はなさげ。
　vSphere ESXi用にインストールして使う

・PernixData FVP
　Fusion-IO,LSI Nytro WarpDriveなどのPCIe系や、普通のSSDに対応
　高速化をはかれるストレージは、FC/SAS/iSCSIとある。
　評価してみようと手配中・・・
　vSphere ESXi用にインストールして使う

今回のIBM FlashCache Storage Acceleratorの特異な点は「FlashCache Storage Acceleratorは、VMware ESXi 5.0/5,1および、Windows Server 2008/2012、Red Hat Enterprise Linux 5/6に対応しています。」という点かも？
これが、Hyper-VとKVMの仮想化環境にも対応しているという意味であれば、他ではない特徴と言えますね。

・・・ほんとにそうなのかな？？？？
FlashCache Storage Acceleratorの製品ページは日米ともにないので、詳細がよくわかりません。

2013/08/21追記

 

IBM FlashCache Storage Acceleratorは、Fusion-ioのioTurbineをベースとし、Fusion-IO以外の製品にも対応させたもの、だそうです。

IBM US側で製品ページ「IBM FlashCache Storage Accelerator」も公開されました。
ただ、ここに掲載されているデータシートの対応システムには、「VMware ESXi 5.0, ESXi 5.1」という記載のみ。
ほんとに、Hyper-VやKVMに対応するの？？？

2013/10/22 追記

 

・SANRAD VXL SoftwareおよびOCZ VXL VMware Acceleration
　SANRAD社が開発したものを、FlashストレージベンダのOCZが買収してるもの
　この製品はESXi向け
　SANRAD社の方の資料を見ると、FC/SAS/iSCSI/NFS全般に使用できるようだ。
日本だとASK社取扱で、そのページには「VMware ESX、Citrix Xen、Microsoft Hyper-V対応」って書かれているのが謎。
　OCZ社のページだと、「VMware ESX」としか書かれてない。

投稿日:

KindleストアにてvSphere 5.0と4.1のHA/DRSなどに関する電子書籍が０円！

YELLOW BRICKにて「Reminder: Free Kindle copy of vSphere 5 and 4.1 Clustering Deepdive」という記事がアップされてた。

見てみると、6/5と6/6は、Kindle版の「vSphere 5.0 Clustering Deepdive」と「vSphere 4.1 HA and DRS Deepdive」が０ドルだと。

日本でもやってるのかな？と見てみたら、やってるじゃないですか！

いそげっ！

投稿日:

SSD+SATAのハイブリッドストレージ Nimble Storageについて調べてみた

Nimble Storageというストレージプロダクトがあるらしい。
それについて調べたことを書いてみる。
うたい文句をみるとTintri VMstoreと似てる感じがするなぁ・・・と思いつつ内容を調査した。

なお、これは以前書いた「Nimble Storage」という記事についてのアップデートです。
簡単に言えば、書いた記事には誤りがあったための更新ついでに、競合との比較です。

Tintri VMstoreと大きく違う点

・Nimble StorageはiSCSIストレージ
　汎用的に使えるiSCSIストレージ
　VMware/Hyper-V/通常のWindows/Citrixで使える
　TintriはNFSストレージで、さらにVMware以外は公式にサポートしない

・SSDはRead Cacheとして使用
　実体は全てSATA HDD上に置かれている
　Tintriは、SSDとSATA HDDのどちらかに置かれており、必要に応じて自動的に移動する

・Web GUI以外の管理手法が完備されている
　SNMP MIB、CLI操作が使える
　Tintriは、Web GUI以外に無い

・vSphere関連のプラグインが一通り揃っている
　VAAI, vSphere Client plugin, SRM pluginがある。
　2013年5月現在TintriはVAAIのみ

・VSS連携も可
　WindowsのVolume Shadowcopy Serviceとの連携も可能

・レプリケーション機能を初期リリースからサポート
　Tintriは、最新のver2.0でサポートのはずだが、2013年5月現在入手できず。

・容量拡張手法がいくつかある
　容量が足らない→Shelf増加（パフォーマンス低下は無い）
　パフォーマンスが足らない1→SSDの容量アップ(オンラインで実施可能)
　パフォーマンスが足らない2→システム追加＋クラスタ化
　Tintriの場合、「システム追加」しかない

・複数システムをクラスタ化できる
　複数のNimble Storageを１システムの様に取り扱うことができる
　ユーザはNimbleを使い分ける、ということを意識する必要は無い
　Tintriの場合、明示的に使い分ける必要がある。

・Web GUIからシステムアップデートができる
　Web GUIからシステムアップデートができる、というのは良くあるが
　アップデートするバージョンを複数から選択できる、というのは珍しい。
　最新は嫌、とか、導入済みのものと合わせたい、という場合に便利。
　Tintriは、本体にキーボードとUSBメモリを取り付けて、コンソール操作でのアップデート。

細かな話

・実データをHDDに書くけど遅いんじゃないの？
もちろん、まともに書くと遅いので、うまくごまかしています。

書き込まれたデータはある一定サイズになるまで、メモリ(NVRAM)上にため込まれます。
既定サイズを超えたら、データ圧縮をおこない、HDDに書き込みます。
ここで既定されているサイズは、SATA HDD 11本で構成されたRAID6に書き込む際に、最速シーケンシャルwriteになるように設定されている。（以降「writing block」と呼びます。なおこの表記はオフィシャルではありません）
つまり、速度が落ちるランダムwriteを排除している、ということになる。

・データ書き換え時ってどうしてるの？
データが書き換えられた時は、書き換え後のデータは通常のwriteデータと共にメモリ上にため込まれます。
そして、通常の書き込みプロセスと同様にwriting block単位で圧縮書き込みされます。
書き換え前のデータは不要になりますが、これはひとまず、メタデータ上のみで無効化されます。
その後、システム負荷を見計らいつつ、データ再配置処理がおこなわれ、空き領域が回収されます。

・え？データは圧縮されてるのに、再配置ってどうやるの？
はい、データが圧縮書き込みされているので、単純な再配置処理ではありません。
再配置は、不要になったデータが含まれているwriting block単位でおこなわれます。
まず、writing block内にある有効なデータをメモリ上に読み込みます。
この読み込んだデータと、通常のwriteデータを合わせて、新規のwriting blockとして、ディスクに書き込みをおこないます。
その後に、元々のwriting blockを無効化し、再利用可能状態にします。

・SSDを冗長化してないけどいいの？
キャッシュでしかないので問題ない。
壊れたらそのSSDを使わなくなるだけで、他のSSDを使って改めてキャッシュされる。
SSDを交換したら、改めて使用される。

・いろいろモデルがあるけどどういう違い？
CS2xxとCS4xxは、CPUの違い
CS220/240/260およびCS420/440/460は、それぞれSATA HDDの容量の違い。
Baseモデルとx2 Flashモデル、x4 Flashモデルの違いは、4本入っているSSDの容量の違い。
例えば、CS220のBaseモデルだったら80GB SSDが4本で320GB、という感じ。

・複数Shelfとかクラスタを組んだ時とかってデータ配置どうなるの？
初期配置としては、均等になるようばらばらに割り振る。
使っていくうちにデータ使用量の偏りが出てくる。
そのような場合は、Re-balance処理が実施され、均等になるように再配置される。
Re-balance処理は低プライオリティで実行されるためパフォーマンス影響は少ない。

・いい資料が見付からないんだけど
Nimble storage Communityを探すといろいろ出てくるよ。

投稿日:

ESXi上でsnapshotをとってあった仮想マシンが起動しない

ESXiで構築した仮想マシンが起動しない。

snapshotをいくつか作ってある仮想マシンの電源を入れようとしたら以下のメッセージが出て起動しない。

——-日本語表記———————
ESXiホスト名 上の 仮想マシン名 をパワーオンでき
ません。 一般的なシステム エラーが発生しました：
エラー
2013/04/25 19:30:36
仮想マシン名
root
——-英語表記———————
Cannot power on 仮想マシン名 on ESXiホスト名
. A general system error occurred:
error
2013/04/25 19:30:36
仮想マシン名
root
—————————-

上記の出力から検索したところ近い事例が２つ
・vCenter 5.0 (Appliance) Issues (Stack Error & Migration Issues)
・RedoLog Corrupt Error and “Failed to clone disk : Bad file descriptor (589833).” when trying to clone

上記２つの内容を簡単に言えば「ESXiを再インストールして治った」とか、「他のデータストアにコピーして治った」とか

VMwareのKnowledgeからは以下の事例が見付かった
・Investigating disk space on an ESX or ESXi host
・ESX, ESXiのディスクスペースの容量調査 (↑の日本語版。ただし版が古い)

これは、起動しない、という対処の一般的な事例として、データストア（ディスク）の空き容量が足らない、という可能性がある、という話。

では、検証。

・データストア（ディスク）の空き容量が足らない可能性について
snapshotデータを統合する場合の作業領域を考えると若干足らない可能性があったので、空き容量をさらに広げた。
→ でも起動せず。（状況変わらず）

・ESXi側の問題について
別のESXiに仮想マシンイメージ全体をコピーして、起動試験。
→ 正常起動

どういうことかな？と考えて見ると、このESXiのサーバって、テスト用サーバで、結構適当な管理をされており、設置場所の都合上、いきなり電源offされたりすることがあった。
どうやら、その時に、ESXiのブートイメージがおかしくなったんじゃないかと想定される。

「hostd-vix-worke: access denied:: dom:appDom(2), obj:vmxSys(66), mode:syscall_allow(2)」とか、怪しすぎる。

まぁ、そんな感じで、結果としては、ESXiの再インストールとなりました。
ただ・・・起動しなくなったのは、とりあえず、仮想マシン１つだけで、他は起動してたんだよね。
その理由はよくわかりませんでした。

# cat /var/log/vmkernel.log
2013-04-25T19:36:46.504Z cpu6:5025)Config: 347: "SIOControlFlag2" = 9, Old Value: 8, (Status: 0x0)
2013-04-25T19:36:46.543Z cpu6:5621)VmkAccess: 637: hostd-vix-worke: access denied:: dom:appDom(2), obj:vmxSys(66), mode:syscall_allow(2)
2013-04-25T19:36:46.543Z cpu6:5621)VmkAccess: 922: VMkernel syscall invalid (1059)
2013-04-25T19:36:46.544Z cpu6:5621)VmkAccess: 637: hostd-vix-worke: access denied:: dom:appDom(2), obj:forkExecSys(88), mode:syscall_allow(2)
2013-04-25T19:36:46.544Z cpu6:5621)VmkAccess: 922: VMkernel syscall invalid (1025)
2013-04-25T19:36:46.608Z cpu2:187170)Config: 347: "SIOControlFlag2" = 8, Old Value: 9, (Status: 0x0)
#
# cat /var/log/hostd.log
2013-04-25T19:36:39.811Z [50F40B90 verbose 'DvsManager'] PersistAllDvsInfo called
2013-04-25T19:36:46.503Z [4FFDCB90 info 'TaskManager' opID=22A33D0D-00000409] Task Created : haTask-24-vim.VirtualMachine.powerOn-500539340
2013-04-25T19:36:46.503Z [FFD81D20 verbose 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] Power on request recieved
2013-04-25T19:36:46.504Z [FFD81D20 verbose 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] Reconfigure ethernet backing if required
2013-04-25T19:36:46.504Z [FFD81D20 info 'ha-eventmgr' opID=22A33D0D-00000409] Event 164 : linuxvm1 on host adminserver in ha-datacenter is starting
2013-04-25T19:36:46.504Z [FFD81D20 info 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] State Transition (VM_STATE_OFF -> VM_STATE_POWERING_ON)
2013-04-25T19:36:46.504Z [FFD81D20 verbose 'ha-host' opID=22A33D0D-00000409] ModeMgr::Begin: op = normal, current = normal, count = 1
2013-04-25T19:36:46.504Z [FFD81D20 verbose 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] Invoking interceptor:3-ha-vmsvc
2013-04-25T19:36:46.504Z [FFD81D20 verbose 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] Done invoking interceptor:3-ha-vmsvc
2013-04-25T19:36:46.505Z [FFD81D20 verbose 'ServiceSystem' opID=22A33D0D-00000409] Invoking command /bin/sh /etc/init.d/xorg status
2013-04-25T19:36:46.506Z [FFD81D20 info 'SysCommandPosix' opID=22A33D0D-00000409] ForkExec(/bin/sh)  191986
2013-04-25T19:36:46.539Z [FFD81D20 verbose 'ServiceSystem' opID=22A33D0D-00000409] Command finished with status 3
2013-04-25T19:36:46.541Z [FFD81D20 verbose 'HostsvcPlugin' opID=22A33D0D-00000409] Security domain hostd24 not found
2013-04-25T19:36:46.541Z [FFD81D20 info 'Libs' opID=22A33D0D-00000409] Vix: [5025 foundryHandleProperties.c:3359]: Error VIX_E_NOT_FOUND in Vix_GetPropertiesImpl(): Unable to get bool property 107.
2013-04-25T19:36:46.541Z [FFD81D20 verbose 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] PowerOn request queued
2013-04-25T19:36:46.542Z [4F6C2B90 verbose 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx'] Retrieved current VM state from foundry 7, 6
2013-04-25T19:36:46.542Z [4FC43B90 info 'vm:VMHSVMCbPower: /vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx']  Setting state of VM to powerOn with option soft
2013-04-25T19:36:46.543Z [4FC43B90 info 'Libs'] Starting vmx as /bin/vmx
2013-04-25T19:36:46.543Z [4FC43B90 info 'Libs'] Starting vmx as /bin/vmx
2013-04-25T19:36:46.544Z [4FC43B90 info 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx']  VMHS: VM /vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx in directory /vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1
2013-04-25T19:36:46.544Z [4FC43B90 info 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx']  VMHS: Exec()'ing /bin/vmx.
2013-04-25T19:36:46.544Z [4FC43B90 info 'Libs'] VMHS: VMKernel_ForkExec(/bin/vmx, detached=1): rc=195887383 pid=132863664
2013-04-25T19:36:46.544Z [4FC43B90 warning 'Libs'] VMHSSpawnVMXUW: unable to spawn /bin/vmx: Operation not permitted
2013-04-25T19:36:46.544Z [4FC43B90 info 'Libs'] VigorClient_StartAndConnect Failed: Failed to launch peer process
2013-04-25T19:36:46.545Z [4FC43B90 info 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx']  Reloading config state.
2013-04-25T19:36:46.595Z [4FC43B90 info 'Libs'] VMHS: Transitioned vmx/execState/val to poweredOff
2013-04-25T19:36:46.607Z [4F681B90 info 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx'] Upgrade is required for virtual machine, version: 8
2013-04-25T19:36:46.607Z [4F681B90 verbose 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx'] Running status of tools changed to: 0
2013-04-25T19:36:46.607Z [4FC43B90 info 'vm:FoundryVMDBPowerOpCallback: VMDB reports power op failed for VM /vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx'] with error msg = "The virtual machine could not start. Make sure VMware ESX is installed correctly. You must also have rights to run the software and access all directories
2013-04-25T19:36:46.607Z [4FB40B90 verbose 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx'] Retrieved current VM state from foundry 5, 2
2013-04-25T19:36:46.607Z [513C3B90 info 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] Failed to do Power Op: Error: (3041) The virtual machine could not start
2013-04-25T19:36:46.608Z [513C3B90 info 'HostsvcPlugin' opID=22A33D0D-00000409] Decremented SIOC Injector Flag2
2013-04-25T19:36:46.641Z [4FC43B90 info 'vm:Vix: [5621 foundryVMPowerOps.c:980]: FoundryVMPowerStateChangeCallback: /vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx']  vmx/execState/val = poweredOff.
2013-04-25T19:36:46.641Z [513C3B90 warning 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] Failed operation
2013-04-25T19:36:46.642Z [513C3B90 info 'ha-eventmgr' opID=22A33D0D-00000409] Event 165 : Cannot power on linuxvm1 on adminserver in ha-datacenter. A general system error occurred:
2013-04-25T19:36:46.642Z [513C3B90 info 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] State Transition (VM_STATE_POWERING_ON -> VM_STATE_OFF)
2013-04-25T19:36:46.642Z [513C3B90 verbose 'ha-host' opID=22A33D0D-00000409] ModeMgr::End: op = normal, current = normal, count = 2
2013-04-25T19:36:46.677Z [513C3B90 info 'ha-host' opID=22A33D0D-00000409] vmxSwapEnabled = true vmmOvhd.anonymous: 25934 vmmOvhd.paged: 50002 vmmOvhd.nonpaged: 12519
2013-04-25T19:36:46.677Z [513C3B90 info 'ha-host' opID=22A33D0D-00000409] vmkOvhd.fixd = 303104 vmkOvhd.variable: 2050 vmkOvhd.selfSwap: 3145728
2013-04-25T19:36:46.677Z [513C3B90 info 'ha-host' opID=22A33D0D-00000409] Computed from lib overhead: 157503488 for (memPages: 1048576, fbSize: 1024, #vcpus: 1, #lsiscsi: 1, #pvscsi: 0, #passthru: 0, #network: 2) vmkOverhead: 11845632
2013-04-25T19:36:46.677Z [513C3B90 info 'ha-host' opID=22A33D0D-00000409] overhead result (no CBRC): 169349120
2013-04-25T19:36:46.677Z [513C3B90 info 'ha-host' opID=22A33D0D-00000409] Predicted overhead: 169349120 for (memory: 4294967296, video: 4194304, #vcpus: 1, autodetect: false, enable3D: false, svgaPtFbSize: 4194304, cbrcOverhead: 0
2013-04-25T19:36:46.677Z [513C3B90 verbose 'vm:/vmfs/volumes/4f8dXXXX-8d9cXXXX-XXXX-XXXXXXXXXXXX/linuxvm1/linuxvm1.vmx' opID=22A33D0D-00000409] Time to gather config: 35 (msecs)
2013-04-25T19:36:46.678Z [4FB81B90 verbose 'Hbrsvc'] Replicator: ReconfigListener triggered for config VM 24
2013-04-25T19:36:46.678Z [513C3B90 info 'HostsvcPlugin' opID=22A33D0D-00000409] Lookupvm: World ID not set for VM 24
2013-04-25T19:36:46.689Z [513C3B90 info 'TaskManager' opID=22A33D0D-00000409] Task Completed : haTask-24-vim.VirtualMachine.powerOn-500539340 Status error
2013-04-25T19:36:46.689Z [4FB81B90 verbose 'Hbrsvc'] Replicator: VmReconfig ignoring VM 24 not configured for replication
2013-04-25T19:36:46.689Z [4FB81B90 info 'Snmpsvc'] VmConfigListener: vm state change received, queueing reload request
2013-04-25T19:36:46.712Z [50FC2B90 warning 'Locale' opID=6E461CB0-00001066] FormatField: Invalid (vim.vm.Message.1)
2013-04-25T19:36:46.712Z [50FC2B90 warning 'Locale' opID=6E461CB0-00001066] FormatField: Invalid (vim.vm.Message.2)
2013-04-25T19:36:46.712Z [50FC2B90 warning 'Locale' opID=6E461CB0-00001066] FormatField: Invalid (vim.vm.Message.3)
2013-04-25T19:36:46.952Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.prov.ProvisioningManager.queryVmLocation.label' expected in module 'task'.
2013-04-25T19:36:46.952Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.prov.ProvisioningManager.queryVmLocation.summary' expected in module 'task'.
2013-04-25T19:36:46.952Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.prov.ProvisioningManager.createShadowVm.label' expected in module 'task'.
2013-04-25T19:36:46.952Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.prov.ProvisioningManager.createShadowVm.summary' expected in module 'task'.
2013-04-25T19:36:46.953Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.NetworkSystem.invokeHostTransactionCall.label' expected in module 'task'.
2013-04-25T19:36:46.953Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.NetworkSystem.invokeHostTransactionCall.summary' expected in module 'task'.
2013-04-25T19:36:46.953Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.NetworkSystem.commitTransaction.label' expected in module 'task'.
2013-04-25T19:36:46.953Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.NetworkSystem.commitTransaction.summary' expected in module 'task'.
2013-04-25T19:36:46.954Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'profile.host.HostProfile.validate.label' expected in module 'task'.
2013-04-25T19:36:46.954Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'profile.host.HostProfile.validate.summary' expected in module 'task'.
2013-04-25T19:36:46.955Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'DistributedVirtualSwitch.lookupPortgroup.label' expected in module 'task'.
2013-04-25T19:36:46.955Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'DistributedVirtualSwitch.lookupPortgroup.summary' expected in module 'task'.
2013-04-25T19:36:46.956Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'HostSystem.queryTpmAttestationReport.label' expected in module 'task'.
2013-04-25T19:36:46.956Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'HostSystem.queryTpmAttestationReport.summary' expected in module 'task'.
2013-04-25T19:36:46.957Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'IpPoolManager.allocateIpv4Address.label' expected in module 'task'.
2013-04-25T19:36:46.957Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'IpPoolManager.allocateIpv4Address.summary' expected in module 'task'.
2013-04-25T19:36:46.957Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'IpPoolManager.allocateIpv6Address.label' expected in module 'task'.
2013-04-25T19:36:46.957Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'IpPoolManager.allocateIpv6Address.summary' expected in module 'task'.
2013-04-25T19:36:46.957Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'IpPoolManager.releaseIpAllocation.label' expected in module 'task'.
2013-04-25T19:36:46.957Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'IpPoolManager.releaseIpAllocation.summary' expected in module 'task'.
2013-04-25T19:36:46.957Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'IpPoolManager.queryIPAllocations.label' expected in module 'task'.
2013-04-25T19:36:46.957Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'IpPoolManager.queryIPAllocations.summary' expected in module 'task'.
2013-04-25T19:36:46.958Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'dvs.DistributedVirtualSwitchManager.lookupPortgroup.label' expected in module 'task'.
2013-04-25T19:36:46.958Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'dvs.DistributedVirtualSwitchManager.lookupPortgroup.summary' expected in module 'task'.
2013-04-25T19:36:46.958Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'profile.host.ProfileManager.retrieveAnswerFileForProfile.label' expected in module 'task'.
2013-04-25T19:36:46.958Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'profile.host.ProfileManager.retrieveAnswerFileForProfile.summary' expected in module 'task'.
2013-04-25T19:36:46.959Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'Datacenter.queryConfigOptionDescriptor.label' expected in module 'task'.
2013-04-25T19:36:46.959Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'Datacenter.queryConfigOptionDescriptor.summary' expected in module 'task'.
2013-04-25T19:36:46.959Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.DatastoreNamespaceManager.CreateDirectory.label' expected in module 'task'.
2013-04-25T19:36:46.959Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.DatastoreNamespaceManager.CreateDirectory.summary' expected in module 'task'.
2013-04-25T19:36:46.959Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.DatastoreNamespaceManager.DeleteDirectory.label' expected in module 'task'.
2013-04-25T19:36:46.959Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.DatastoreNamespaceManager.DeleteDirectory.summary' expected in module 'task'.
2013-04-25T19:36:46.960Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.retrieveVmRecoveryInfo.label' expected in module 'task'.
2013-04-25T19:36:46.960Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.retrieveVmRecoveryInfo.summary' expected in module 'task'.
2013-04-25T19:36:46.960Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.retrieveLastVmMigrationStatus.label' expected in module 'task'.
2013-04-25T19:36:46.960Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.retrieveLastVmMigrationStatus.summary' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.reserveFiles.label' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.reserveFiles.summary' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.deleteFiles.label' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.deleteFiles.summary' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.extractNvramContent.label' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'host.LowLevelProvisioningManager.extractNvramContent.summary' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.retrieveConfigValue.label' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.retrieveConfigValue.summary' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.updateConfigValue.label' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.updateConfigValue.summary' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.initiateProductInfoQuery.label' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.initiateProductInfoQuery.summary' expected in module 'task'.
2013-04-25T19:36:46.961Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.initiateProductInstall.label' expected in module 'task'.
2013-04-25T19:36:46.962Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.initiateProductInstall.summary' expected in module 'task'.
2013-04-25T19:36:46.962Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.retrieveJobStatus.label' expected in module 'task'.
2013-04-25T19:36:46.962Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.retrieveJobStatus.summary' expected in module 'task'.
2013-04-25T19:36:46.962Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.retrieveJobResults.label' expected in module 'task'.
2013-04-25T19:36:46.962Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'vm.guest.GuestUpdateAgent.retrieveJobResults.summary' expected in module 'task'.
2013-04-25T19:36:46.962Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'dvs.VmwareDistributedVirtualSwitch.lookupPortgroup.label' expected in module 'task'.
2013-04-25T19:36:46.962Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'dvs.VmwareDistributedVirtualSwitch.lookupPortgroup.summary' expected in module 'task'.
2013-04-25T19:36:46.963Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'ExtensionManager.queryExtensionIpAllocationUsage.label' expected in module 'task'.
2013-04-25T19:36:46.963Z [4FF5BB90 verbose 'Locale' opID=22A33D0D-0000040E] Default resource used for 'ExtensionManager.queryExtensionIpAllocationUsage.summary' expected in module 'task'.
2013-04-25T19:36:51.691Z [4F6C2B90 info 'Snmpsvc'] DoReport: VM Poll State cache - report starting
2013-04-25T19:36:51.694Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 8
2013-04-25T19:36:51.697Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 9
2013-04-25T19:36:51.700Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 14
2013-04-25T19:36:51.703Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 18
2013-04-25T19:36:51.706Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 19
2013-04-25T19:36:51.709Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 21
2013-04-25T19:36:51.712Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 24
2013-04-25T19:36:51.714Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 27
2013-04-25T19:36:51.718Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 28
2013-04-25T19:36:51.721Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 30
2013-04-25T19:36:51.723Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 31
2013-04-25T19:36:51.726Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 34
2013-04-25T19:36:51.729Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 41
2013-04-25T19:36:51.732Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 43
2013-04-25T19:36:51.734Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 45
2013-04-25T19:36:51.737Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 46
2013-04-25T19:36:51.740Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 47
2013-04-25T19:36:51.743Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 48
2013-04-25T19:36:51.746Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 49
2013-04-25T19:36:51.749Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 58
2013-04-25T19:36:51.752Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 59
2013-04-25T19:36:51.755Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 60
2013-04-25T19:36:51.758Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 62
2013-04-25T19:36:51.761Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 65
2013-04-25T19:36:51.764Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 71
2013-04-25T19:36:51.767Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 81
2013-04-25T19:36:51.770Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 83
2013-04-25T19:36:51.773Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 84
2013-04-25T19:36:51.777Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 86
2013-04-25T19:36:51.780Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 87
2013-04-25T19:36:51.783Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 88
2013-04-25T19:36:51.786Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 89
2013-04-25T19:36:51.789Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 91
2013-04-25T19:36:51.792Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 94
2013-04-25T19:36:51.794Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 95
2013-04-25T19:36:51.797Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 96
2013-04-25T19:36:51.800Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 97
2013-04-25T19:36:51.802Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 98
2013-04-25T19:36:51.815Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 101
2013-04-25T19:36:51.828Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 102
2013-04-25T19:36:51.837Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 103
2013-04-25T19:36:51.841Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 104
2013-04-25T19:36:51.844Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 105
2013-04-25T19:36:51.847Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 106
2013-04-25T19:36:51.850Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 107
2013-04-25T19:36:51.853Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 110
2013-04-25T19:36:51.857Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 111
2013-04-25T19:36:51.860Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 112
2013-04-25T19:36:51.864Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 114
2013-04-25T19:36:51.867Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 115
2013-04-25T19:36:51.869Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 116
2013-04-25T19:36:51.872Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 117
2013-04-25T19:36:51.875Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 118
2013-04-25T19:36:51.878Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 119
2013-04-25T19:36:51.881Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 120
2013-04-25T19:36:51.883Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 121
2013-04-25T19:36:51.887Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 122
2013-04-25T19:36:51.890Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 123
2013-04-25T19:36:51.893Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 124
2013-04-25T19:36:51.897Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 125
2013-04-25T19:36:51.900Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 126
2013-04-25T19:36:51.903Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 127
2013-04-25T19:36:51.906Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 128
2013-04-25T19:36:51.909Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 129
2013-04-25T19:36:51.912Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 130
2013-04-25T19:36:51.915Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 131
2013-04-25T19:36:51.918Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: processing vm 132
2013-04-25T19:36:51.918Z [4F6C2B90 info 'Snmpsvc'] ReportVMs: serialized 67 out of 67 vms
2013-04-25T19:36:51.918Z [4F6C2B90 info 'Snmpsvc'] GenerateFullReport: report file /tmp/.vm-report.xml generated, size 2310 bytes.
2013-04-25T19:36:51.918Z [4F6C2B90 info 'Snmpsvc'] PublishReport: file /tmp/.vm-report.xml published as /tmp/vm-report.xml
2013-04-25T19:36:51.918Z [4F6C2B90 info 'Snmpsvc'] NotifyAgent: write(73, /var/run/snmp.ctl, V) 1 bytes to snmpd
2013-04-25T19:36:51.918Z [4F6C2B90 info 'Snmpsvc'] GenerateFullReport: notified snmpd to update vm cache
2013-04-25T19:36:51.918Z [4F6C2B90 info 'Snmpsvc'] DoReport: VM Poll State cache - report completed ok
2013-04-25T19:36:53.007Z [5001DB90 trivia 'Snmpsvc:http.HTTPService'] HTTP Response: Setting Content-Length: -1
2013-04-25T19:36:53.007Z [5001DB90 verbose 'Snmpsvc:http.HTTPService.HttpConnection'] User agent is 'No-User-Agent'
2013-04-25T19:36:53.007Z [5001DB90 trivia 'Snmpsvc:http.HTTPService.HttpConnection'] User agent 'No-User-Agent' is non-chunking: false
2013-04-25T19:36:53.007Z [5001DB90 trivia 'Snmpsvc:http.HTTPService.HttpConnection'] User agent 'No-User-Agent' needs Content-Length: false
2013-04-25T19:36:53.007Z [5001DB90 trivia 'Snmpsvc:http.HTTPService.HttpConnection'] Lookup handler by prefix for: /
2013-04-25T19:36:53.007Z [5001DB90 trivia 'Snmpsvc:http.HTTPService.HttpConnection'] Inspecting path: /
2013-04-25T19:36:53.007Z [5001DB90 trivia 'Snmpsvc:http.HTTPService.HttpConnection'] No match found for: /
2013-04-25T19:36:53.007Z [5001DB90 trivia 'Snmpsvc:http.HTTPService.HttpConnection'] ProcessRequest: using default handler
2013-04-25T19:36:53.007Z [5001DB90 verbose 'Snmpsvc-env'] HandlePost
2013-04-25T19:36:53.007Z [5001DB90 verbose 'Snmpsvc-env'] HandleRequest
2013-04-25T19:36:53.007Z [5001DB90 verbose 'Snmpsvc-env'] Push starting indication parser
2013-04-25T19:36:53.008Z [5001DB90 verbose 'Snmpsvc-env'] ProcessIndications started threadid=1342299024
2013-04-25T19:36:54.009Z [5001DB90 verbose 'Snmpsvc-env'] FetchClassDef: connect to cimom @ 127.0.0.1:5988
2013-04-25T19:36:54.010Z [5001DB90 verbose 'Snmpsvc-env'] FetchClassDef: making request class VMware_CIMHeartbeat, ns root/cimv2
2013-04-25T19:36:54.014Z [5001DB90 verbose 'Snmpsvc-env'] FetchClassDef: got response from cimom
2013-04-25T19:36:54.014Z [5001DB90 verbose 'Snmpsvc-env'] FetchClassDef: http response code from cimom: 200 OK
2013-04-25T19:36:54.014Z [5001DB90 error 'Snmpsvc-env'] OnEndElement: no _props to update value, skipping
2013-04-25T19:36:54.014Z [5001DB90 verbose 'Snmpsvc-env'] parse class definition msg ok: WBEMHandler @0x62a0670 = {_state: 3, _mode: 5, _className: VMware_CIMHeartbeat, _identifier: MIB.IETF| 1.3.6.1.4.1.6876.4.90.0.401, _props = { (IndicationTime,datetime,MIB.IETF|1| 1.3.6.1.4.1.6876.4.30.3.0,0), }}
2013-04-25T19:36:54.014Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds skipping property name='stamp', value='922', no oid info from class def keys:(IndicationTime, )
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds skipping property name='hostname', value='adminserver', no oid info from class def keys:(IndicationTime, )
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds skipping property name='SequenceNumber', value='', no oid info from class def keys:(IndicationTime, )
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds skipping property name='SequenceContext', value='', no oid info from class def keys:(IndicationTime, )
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds skipping property name='IndicationFilterName', value='com.vmware:vim.snmpagent-root/cimv2', no oid info from class def keys:(IndicationTime, )
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds skipping property name='OtherSeverity', value='', no oid info from class def keys:(IndicationTime, )
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds skipping property name='PerceivedSeverity', value='', no oid info from class def keys:(IndicationTime, )
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds skipping property name='CorrelatedIndications', value='', no oid info from class def keys:(IndicationTime, )
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds skipping property name='IndicationIdentifier', value='', no oid info from class def keys:(IndicationTime, )
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc-env'] GenerateVarbinds indication VMware_CIMHeartbeat(1.3.6.1.4.1.6876.4.90.0.401) has 1 properties with mapping qualifiers. Indication had 10, ClassDef had 1 props each.
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc'] GenEvent: oid: 1.3.6.1.4.1.6876.4.90.0.401
2013-04-25T19:36:54.015Z [5001DB90 verbose 'Snmpsvc'] ConvertId: ent:1.3.6.1.4.1.6876.4.90 spec 401
2013-04-25T19:36:54.015Z [5001DB90 info 'Snmpsvc'] ConvertVarbinds: convert id=1.3.6.1.4.1.6876.4.30.3.0: type=dateTimeTC, value=20130422101653.000000+000
2013-04-25T19:36:54.015Z [5001DB90 info 'Snmpsvc'] GenEvent: sending trap (generic=6 specific=401 ent_sz=9) with id: 1.3.6.1.4.1.6876.4.90., vbs: 1
2013-04-25T19:36:54.015Z [5001DB90 info 'Snmpsvc'] WriteV1Trap: generic 6 specific 401
2013-04-25T19:36:54.015Z [5001DB90 info 'Snmpsvc'] WriteV1Trap: serialized 1 varbinds
2013-04-25T19:36:54.016Z [5001DB90 info 'Snmpsvc'] WriteV1Trap: wrote 88 bytes
2013-04-25T19:36:54.016Z [5001DB90 info 'Snmpsvc'] NotifyAgent: write(88, /var/run/snmp.ctl, N) 1 bytes to snmpd
2013-04-25T19:36:54.016Z [5001DB90 info 'Snmpsvc'] WriteV1Trap: agent was  notified
2013-04-25T19:36:54.016Z [5001DB90 verbose 'Snmpsvc:http.HTTPService'] HTTP Response: Complete (processed 0 bytes)
2013-04-25T19:36:54.016Z [5001DB90 trivia 'Snmpsvc:http.HTTPService'] HTTP Response: Flush(lastBlock = true)
2013-04-25T19:36:54.016Z [5001DB90 trivia 'Snmpsvc:http.HTTPService'] HTTP Response: Client: NeedsContentLength: false UnderstandsChunking: true CanKeepAlive: true (PresetContentLength -1)
2013-04-25T19:36:54.016Z [5001DB90 trivia 'Snmpsvc:http.HTTPService'] HTTP Response: SetKeepAlive(true)
2013-04-25T19:36:54.016Z [5001DB90 trivia 'Snmpsvc:http.HTTPService'] HTTP Response: Setting Content-Length: 0
2013-04-25T19:36:54.016Z [5001DB90 trivia 'Snmpsvc:http.HTTPService'] HTTP Response: Header size is 163
2013-04-25T19:36:54.016Z [5001DB90 trivia 'Snmpsvc:http.HTTPService'] HTTP Response: Writing 163 bytes to stream
2013-04-25T19:36:54.016Z [5001DB90 trivia 'Snmpsvc:http.HTTPService.HttpConnection'] ResponseCompleted(false), request keep alive true, closeStream false
2013-04-25T19:36:54.016Z [5001DB90 verbose 'Snmpsvc-env'] ProcessIndications completed, 1 indication(s) processed
2013-04-25T19:36:54.016Z [4FE99B90 trivia 'Snmpsvc:http.HTTPService'] HTTP Response: Setting Content-Length: -1
2013-04-25T19:36:55.016Z [500E0B90 verbose 'HttpConnectionPool-000000'] [RemoveConnection] Connection removed; cnx: TCPClientSocket(this=50d773d0, state=CLOSED, _connectSocket=TCP(null), error=(null)) TCP(<null>); pooled: 0
#