Alarm Hostverbindung und -betriebszustand

[JanP]

Hallo,
ich habe einen Cluster mit 3 HP-Servern, MSA und ESX4.1/Vsphere.
Der VCenter Server läuft in einer 2008R2-VM auf dem Cluster.

Ich bekomme unregelmäßig alle paar Tage Fehlermeldungen per Mail, das einer der drei Hosts nicht reagiert. Alle VM´s sind durchweg erreichbar und auch sonst sind keine Fehler erkennbar.
Die Server haben eine Uptime von > 200 Tagen, das selbe gilt für die Switche (redunant)
Firewall und Virenscanner habe ich testweise auf der VCenter-VM deaktiviert, daran lag es nicht.
Text der Email lautet wie folgt:

Code: Alles auswählen

[VMware vCenter - Alarm Fehler bei Hostverbindung] Der Host 172.10.xxx.xxx in Firma reagiert nicht.
(IP und Firmenname geändert)

Ziel: 172.19.2.192
Alter Status: Grün
Neuer Status: Rot
 
Alarmdefinition:
([Status Rot ist gleich notResponding] UND [Status Rot ungleich standBy])
 
Aktuelle Werte für Metrik/Status:
 Status = Keine Antwort UND Status = Unbekannt
 
Beschreibung:
Alarm 'Hostverbindung und -betriebszustand' auf 172.19.xxx.xxx wurde von Grün in Rot geändert



Ich kann leider kein Attachment anfügen, hier mal der entsprechende Auszug aus dem Vcenter Server Protokoll:

Code: Alles auswählen

[size=9][2011-06-11 03:02:46.876 02512 error 'App' opID=task-internal-1-f9a0b0da-6] [VpxdDrmInterface] Vm id -2147219169 not found.
[2011-06-11 03:02:46.876 02512 error 'App' opID=task-internal-1-f9a0b0da-6] [VpxdDrmInterface] Vm id -2147219168 not found.
[2011-06-11 03:02:46.876 02512 error 'App' opID=task-internal-1-f9a0b0da-6] [VpxdDrmInterface] Vm id -2147219167 not found.
[2011-06-11 03:02:46.876 02512 error 'App' opID=task-internal-1-f9a0b0da-6] [VpxdDrmInterface] Vm id -2147219166 not found.
[2011-06-11 03:02:46.876 02512 error 'App' opID=task-internal-1-f9a0b0da-6] [VpxdDrmInterface] Vm id -2147219165 not found.
[2011-06-11 03:02:46.876 02512 error 'App' opID=task-internal-1-f9a0b0da-6] [VpxdDrmInterface] Vm id -2147219164 not found.
[2011-06-11 03:02:46.876 02512 error 'App' opID=task-internal-1-f9a0b0da-6] [VpxdDrmInterface] Vm id -2147219163 not found.
[2011-06-11 03:02:46.876 02512 error 'App' opID=task-internal-1-f9a0b0da-6] [VpxdDrmInterface] Vm id -2147219162 not found.
[2011-06-11 03:02:46.876 02512 info 'App' opID=task-internal-1-f9a0b0da-6] [VpxLRO] -- FINISH task-internal-20259 --  -- AskRefreshDrmRecLro --
[2011-06-11 03:04:25.626 02540 info 'App' opID=HB-host-41@76104] [VpxLRO] -- BEGIN task-internal-20260 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:04:25.626 02540 info 'App' opID=HB-host-41@76104] [VpxdHostSync] Synchronizing host: 172.19.2.192 (172.19.2.192)
[2011-06-11 03:04:46.673 02496 error 'App'] [VpxdVmomi] Got vmacore exception: Ein Verbindungsversuch ist fehlgeschlagen, da die Gegenstelle nach einer bestimmten Zeitspanne nicht richtig reagiert hat, oder die hergestellte Verbindung war fehlerhaft, da der verbundene Host nicht reagiert hat.
[2011-06-11 03:04:46.673 02496 error 'App'] [VpxdVmomi] Backtrace:
backtrace[00] rip 000000018010a1aa Vmacore::System::Stacktrace::CaptureWork
backtrace[01] rip 00000001800e8018 Vmacore::System::SystemFactoryImpl::CreateFileWriter
backtrace[02] rip 00000001800e850e Vmacore::System::SystemFactoryImpl::CreateQuickBacktrace
backtrace[03] rip 0000000180077ed8 Vmacore::Throwable::Throwable
backtrace[04] rip 0000000180108603 Vmacore::SystemException::SystemException
backtrace[05] rip 000000018011a96a Vmacore::System::GetThisThread
backtrace[06] rip 00000001801237ac Vmacore::System::IsEnlisted
backtrace[07] rip 0000000180119915 Vmacore::System::GetThreadId
backtrace[08] rip 00000000729d2fdf endthreadex
backtrace[09] rip 00000000729d3080 endthreadex
backtrace[10] rip 000000007746f56d BaseThreadInitThunk
backtrace[11] rip 00000000775a2cc1 RtlUserThreadStart
[2011-06-11 03:04:46.704 02540 warning 'VpxProfiler' opID=HB-host-41@76104] [VpxdHostSync] GetChanges host:172.19.2.192 (172.19.2.192) took 21078 ms
[2011-06-11 03:04:46.704 02540 warning 'VpxProfiler' opID=HB-host-41@76104] [VpxdHostSync] DoHostSync:00000000073138C0 took 21078 ms
[2011-06-11 03:04:46.736 02540 warning 'VpxProfiler' opID=HB-host-41@76104] InvtHostSyncLRO::StartWork took 21110 ms
[2011-06-11 03:04:46.736 02540 info 'App' opID=HB-host-41@76104] [VpxLRO] -- FINISH task-internal-20260 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:04:47.736 03264 info 'App' opID=task-internal-20261-61f1995] [VpxLRO] -- BEGIN task-internal-20261 --  -- ScheduledTaskLRO --
[2011-06-11 03:04:47.751 02424 info 'App' opID=task-internal-20262-efe77c7e] [VpxLRO] -- BEGIN task-internal-20262 --  -- ScheduledTaskLRO --
[2011-06-11 03:04:48.142 02424 info 'App' opID=task-internal-20262-efe77c7e] [VpxLRO] -- FINISH task-internal-20262 --  -- ScheduledTaskLRO --
[2011-06-11 03:04:48.142 03264 info 'App' opID=task-internal-20261-61f1995] [VpxLRO] -- FINISH task-internal-20261 --  -- ScheduledTaskLRO --
[2011-06-11 03:04:55.658 02424 info 'App' opID=HB-host-41@76104] [VpxLRO] -- BEGIN task-internal-20263 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:04:55.658 02424 info 'App' opID=HB-host-41@76104] [VpxdHostSync] Synchronizing host: 172.19.2.192 (172.19.2.192)
[2011-06-11 03:04:56.439 02700 info 'App' opID=HB-host-28@139335] [VpxLRO] -- BEGIN task-internal-20264 -- host-28 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:04:56.439 02700 info 'App' opID=HB-host-28@139335] [VpxdHostSync] Synchronizing host: 172.19.2.194 (172.19.2.194)
[2011-06-11 03:04:56.658 02424 info 'App' opID=HB-host-41@76104] [VpxdHostSync] Retrieved host update to 76104
[2011-06-11 03:04:56.861 02424 info 'App' opID=HB-host-41@76104] [VpxdMoHost::UpdateConfigInt] Marked 172.19.2.192 as dirty.
[2011-06-11 03:04:57.095 02424 info 'StackTracer' opID=HB-host-41@76104] [2424] Enter DAS_PROFILE UpdateDasStatus
[2011-06-11 03:04:57.095 02424 info 'App' opID=HB-host-41@76104] [VpxdDas] Bad primary bmhesx1: connected=0, dasState=running, vpxaDasState=running
[2011-06-11 03:04:57.095 02424 info 'StackTracer' opID=HB-host-41@76104] [2424] Exit DAS_PROFILE UpdateDasStatus (0 ms)
[2011-06-11 03:04:57.095 02424 warning 'App' opID=HB-host-41@76104] [VpxdMoHost::GetLinkedVmInt] Getting linked vm for vmid 23 on host 172.19.2.192 - COULD NOT FIND IT
[2011-06-11 03:04:57.095 02424 warning 'App' opID=HB-host-41@76104] [VpxdMoHost::GetLinkedVmInt] Getting linked vm for vmid 24 on host 172.19.2.192 - COULD NOT FIND IT
[2011-06-11 03:04:57.095 02424 warning 'App' opID=HB-host-41@76104] [VpxdMoHost::GetLinkedVmInt] Getting linked vm for vmid 27 on host 172.19.2.192 - COULD NOT FIND IT
[2011-06-11 03:04:57.111 02424 info 'App' opID=HB-host-41@76104] [VpxdMoVm::OverheadCache::Invalidate] VM vim.VirtualMachine:vm-61: config changed, invalidating cache...
[2011-06-11 03:04:57.111 02424 info 'App' opID=HB-host-41@76104] [VpxdMoVm::OverheadCache::Invalidate] VM vim.VirtualMachine:vm-235: config changed, invalidating cache...
[2011-06-11 03:04:57.126 02424 info 'App' opID=HB-host-41@76104] [VpxdMoVm::OverheadCache::Invalidate] VM vim.VirtualMachine:vm-45: config changed, invalidating cache...
[2011-06-11 03:04:57.204 02424 info 'App' opID=HB-host-41@76104] [VpxdHostSync] Completed host synchronization
[2011-06-11 03:04:57.204 02424 info 'App' opID=HB-host-41@76104] [VpxdHostSpecSync] saving host update to vpxaMasterSpecGenNo = 0, vpxdMasterSpecGenNo = 382
[2011-06-11 03:04:57.204 02424 info 'App' opID=HB-host-41@76104] [VpxdHostSpecSync] Updating vpxa for 172.19.2.192 (spec. genno 382)
[2011-06-11 03:04:57.470 02700 info 'App' opID=HB-host-28@139335] [VpxdHostSync] Retrieved host update to 139335
[2011-06-11 03:04:57.517 02700 info 'App' opID=HB-host-28@139335] [VpxdHostSync] Completed host synchronization
[2011-06-11 03:04:57.517 02700 info 'App' opID=HB-host-28@139335] [VpxdHostSpecSync] saving host update to vpxaMasterSpecGenNo = 382, vpxdMasterSpecGenNo = 383
[2011-06-11 03:04:57.517 02700 info 'App' opID=HB-host-28@139335] [VpxdHostSpecSync] Updating vpxa for 172.19.2.194 (spec. genno 383)
[2011-06-11 03:04:57.517 02700 info 'App' opID=HB-host-28@139335] [VpxLRO] -- FINISH task-internal-20264 -- host-28 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:00.001 02700 info 'App'] [VpxdStatsCollector::CollectRemote] 2 threads doing remote collection
[2011-06-11 03:05:02.033 02424 warning 'VpxProfiler' opID=HB-host-41@76104] VpxdClientAdapter::InvokeOnSoap: (172.19.2.192, vpxapi.VpxaService.setConfig) took 4829 ms
[2011-06-11 03:05:02.033 02424 warning 'VpxProfiler' opID=HB-host-41@76104] [VpxdHostSync] DoHostSpecSync:00000000073138C0[VpxdHostSync] PrepareUpdateHost:00000000073138C0[VpxdHostSync] SetConfigTime:00000000073138C0 took 4829 ms
[2011-06-11 03:05:02.033 02424 warning 'VpxProfiler' opID=HB-host-41@76104] [VpxdHostSync] DoHostSpecSync:00000000073138C0 took 4829 ms
[2011-06-11 03:05:02.220 02424 info 'App' opID=HB-host-41@76104] [VpxdMoHost::UpdateConnectionStateInt] Marked 172.19.2.192 as dirty.
[2011-06-11 03:05:02.236 02424 warning 'VpxProfiler' opID=HB-host-41@76104] InvtHostSyncLRO::StartWork took 6578 ms
[2011-06-11 03:05:02.236 02424 info 'App' opID=HB-host-41@76104] [VpxLRO] -- FINISH task-internal-20263 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:06.439 02512 info 'App' opID=HB-host-28@139336] [VpxLRO] -- BEGIN task-internal-20265 -- host-28 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:06.439 02512 info 'App' opID=HB-host-28@139336] [VpxdHostSync] Synchronizing host: 172.19.2.194 (172.19.2.194)
[2011-06-11 03:05:07.205 02540 info 'App' opID=HB-host-41@76109] [VpxLRO] -- BEGIN task-internal-20266 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:07.220 02540 info 'App' opID=HB-host-41@76109] [VpxdHostSync] Synchronizing host: 172.19.2.192 (172.19.2.192)
[2011-06-11 03:05:07.501 02512 info 'App' opID=HB-host-28@139336] [VpxdHostSync] Retrieved host update to 139336
[2011-06-11 03:05:07.564 02512 info 'App' opID=HB-host-28@139336] [VpxdHostSync] Completed host synchronization
[2011-06-11 03:05:07.564 02512 info 'App' opID=HB-host-28@139336] [VpxLRO] -- FINISH task-internal-20265 -- host-28 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:08.126 02540 info 'App' opID=HB-host-41@76109] [VpxdHostSync] Retrieved host update to 76109
[2011-06-11 03:05:08.173 02540 info 'App' opID=HB-host-41@76109] [VpxdMoHost::UpdateConfigInt] Marked 172.19.2.192 as dirty.
[2011-06-11 03:05:08.205 02540 info 'App' opID=HB-host-41@76109] [VpxdHostSync] Completed host synchronization
[2011-06-11 03:05:08.220 02540 info 'App' opID=HB-host-41@76109] [VpxdHostSpecSync] saving host update to vpxaMasterSpecGenNo = 382, vpxdMasterSpecGenNo = 386
[2011-06-11 03:05:08.220 02540 info 'App' opID=HB-host-41@76109] [VpxdHostSpecSync] Updating vpxa for 172.19.2.192 (spec. genno 386)
[2011-06-11 03:05:08.392 02540 info 'App' opID=HB-host-41@76109] [VpxLRO] -- FINISH task-internal-20266 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:17.220 03264 info 'App' opID=HB-host-41@76111] [VpxLRO] -- BEGIN task-internal-20267 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:17.220 03264 info 'App' opID=HB-host-41@76111] [VpxdHostSync] Synchronizing host: 172.19.2.192 (172.19.2.192)
[2011-06-11 03:05:18.048 03264 info 'App' opID=HB-host-41@76111] [VpxdHostSync] Retrieved host update to 76111
[2011-06-11 03:05:18.126 03264 info 'App' opID=HB-host-41@76111] [VpxdMoHost::UpdateConfigInt] Marked 172.19.2.192 as dirty.
[2011-06-11 03:05:18.126 03264 info 'App' opID=HB-host-41@76111] [VpxdHostSync] Completed host synchronization
[2011-06-11 03:05:18.126 03264 info 'App' opID=HB-host-41@76111] [VpxLRO] -- FINISH task-internal-20267 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:27.236 02208 info 'App' opID=HB-host-41@76112] [VpxLRO] -- BEGIN task-internal-20268 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:27.236 02208 info 'App' opID=HB-host-41@76112] [VpxdHostSync] Synchronizing host: 172.19.2.192 (172.19.2.192)
[2011-06-11 03:05:27.283 02208 info 'App' opID=HB-host-41@76112] [VpxdHostSync] Retrieved host update to 76112
[2011-06-11 03:05:27.283 02208 info 'App' opID=HB-host-41@76112] [VpxdHostSync] Completed host synchronization
[2011-06-11 03:05:27.283 02208 info 'App' opID=HB-host-41@76112] [VpxLRO] -- FINISH task-internal-20268 -- host-41 -- VpxdInvtHostSyncHostLRO.Synchronize --
[2011-06-11 03:05:31.111 01888 info 'StackTracer'] [1888] Enter DAS_PROFILE UpdateDasStatus
[2011-06-11 03:05:31.111 01888 info 'StackTracer'] [1888] Exit DAS_PROFILE UpdateDasStatus (0 ms)
[2011-06-11 03:05:32.236 02496 info 'App' opID=task-internal-1-f9a0b0da-3e] [VpxLRO] -- BEGIN task-internal-20269 --  -- AskRefreshDrmRecLro --
[2011-06-11 03:05:32.236 02496 info 'App' opID=task-internal-1-f9a0b0da-3e] [ClusterCompatibilitySet::ComputeCompatibilitySet] Before lock Dirty hosts: 1 ; Dirty VMs: 3 ; Clean hosts: 2 ; Clean VMs: 4
[2011-06-11 03:05:32.236 02496 info 'App' opID=task-internal-1-f9a0b0da-3e-54] [VpxLRO] -- BEGIN task-internal-20270 --  -- VmTestDriver --
[2011-06-11 03:05:32.252 02496 info 'App' opID=task-internal-1-f9a0b0da-3e-54] [VpxLRO] -- FINISH task-internal-20270 --  -- VmTestDriver --
[2011-06-11 03:05:32.252 02496 info 'App' opID=task-internal-1-f9a0b0da-3e-91] [VpxLRO] -- BEGIN task-internal-20271 --  -- VmTestDriver --
[2011-06-11 03:05:32.252 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.252 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.252 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.252 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.267 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.267 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.267 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.267 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.267 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.267 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.283 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.283 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-91] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.283 02496 info 'App' opID=task-internal-1-f9a0b0da-3e-91] [VpxLRO] -- FINISH task-internal-20271 --  -- VmTestDriver --
[2011-06-11 03:05:32.283 02496 info 'App' opID=task-internal-1-f9a0b0da-3e-b0] [VpxLRO] -- BEGIN task-internal-20272 --  -- VmTestDriver --
[2011-06-11 03:05:32.283 02496 info 'App' opID=task-internal-1-f9a0b0da-3e-b0] [VpxLRO] -- FINISH task-internal-20272 --  -- VmTestDriver --
[2011-06-11 03:05:32.283 02496 info 'App' opID=task-internal-1-f9a0b0da-3e-40] [VpxLRO] -- BEGIN task-internal-20273 --  -- VmTestDriver --
[2011-06-11 03:05:32.283 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-40] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.283 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-40] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.298 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-40] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.298 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-40] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.298 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-40] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.298 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-40] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.298 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-40] [2496] Enter DAS_PROFILE CheckVmotion
[2011-06-11 03:05:32.298 02496 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e-40] [2496] Exit DAS_PROFILE CheckVmotion (0 ms)
[2011-06-11 03:05:32.298 02496 info 'App' opID=task-internal-1-f9a0b0da-3e-40] [VpxLRO] -- FINISH task-internal-20273 --  -- VmTestDriver --
[2011-06-11 03:05:32.314 01888 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e] [1888] Enter DAS_PROFILE UpdateDasStatus
[2011-06-11 03:05:32.314 01888 info 'StackTracer' opID=task-internal-1-f9a0b0da-3e] [1888] Exit DAS_PROFILE UpdateDasStatus (0 ms)
[2011-06-11 03:05:32.330 02496 info 'App' opID=task-internal-1-f9a0b0da-3e] [Drm] Drmdump written: C:\ProgramData\VMware\VMware VirtualCenter\Logs/drmdump/cluster26/12952227932314-proposeActions.dump
[2011-06-11 03:05:32.345 02496 info 'App' opID=task-internal-1-f9a0b0da-3e] [Drm] host-on LogHostDemand: host 172.19.2.194 cpu 1385 mem 2183, host 172.19.2.192 cpu 2131 mem 1803, host 172.19.2.193 cpu 186 mem 1019, TOTAL cpu 3702 mem 5005
[2011-06-11 03:05:32.345 02496 info 'App' opID=task-internal-1-f9a0b0da-3e] [Drm] host-off LogHostDemand: host 172.19.2.194 cpu 1385 mem 2183, host 172.19.2.192 cpu 2131 mem 1803, host 172.19.2.193 cpu 186 mem 1019, TOTAL cpu 3702 mem 5005
[2011-06-11 03:05:32.345 02496 info 'App' opID=task-internal-1-f9a0b0da-3e] [Drm] LogActiveCapacity: cpu 92340 mem 132697
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219161 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219160 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219159 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219158 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219157 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219156 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219155 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219154 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219153 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219152 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219151 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219150 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219149 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219148 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219147 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219146 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219145 not found.
[2011-06-11 03:05:32.345 02496 error 'App' opID=task-internal-1-f9a0b0da-3e] [VpxdDrmInterface] Vm id -2147219144 not found. [/size]


Was kann mir diese (falschen?) Fehlermeldungen verursachen?

Zu der Zeit liefen keine Backups, kein Netzwerkport war down, die CPU/RAM Auslastung liegt bei ~2-10%, Netzwerk zu dem Zeitpunkt bei ~1%

Ich danke euch und wünsche noch frohe Pfingsten.

[Tschoergez]

Hi!
Was sagen denn die vmkernel-logs und vmware-hostd.log und vmware-vpxa.log auf den betreffenden ESX-Server zu dem Zeitpunkt?

Manchmal sorgen Storage Failover dafür, dass der ESX kurzzeitig nicht mehr reagiert und die Heartbeats zum vCenter unterbrochen sind...

Viele Grüße,
jörg

[JanP]

Hallo Jörg, anbei die Kernel und Hostd Logs.
Meine vpxa-logs gehen nicht soweit zurück. (Es sind doch die in /var/log/vmware/vpx?)

Kernel:

Code: Alles auswählen

Jun 11 03:00:19 bmhesx1 vmkernel: 206:12:55:02.522 cpu0:4254)WARNING: ScsiScan: 535: Path 'vmhba1:C0:T1:L0': devclass has changed:  devclass=0xd
Jun 11 03:00:19 bmhesx1 vmkernel: 206:12:55:02.523 cpu4:4254)WARNING: ScsiScan: 535: Path 'vmhba2:C0:T0:L0': devclass has changed:  devclass=0xd
Jun 11 03:00:19 bmhesx1 vmkernel: 206:12:55:02.524 cpu4:4254)WARNING: ScsiScan: 535: Path 'vmhba1:C0:T0:L0': devclass has changed:  devclass=0xd
Jun 11 03:00:19 bmhesx1 vmkernel: 206:12:55:02.524 cpu4:4254)WARNING: ScsiScan: 535: Path 'vmhba2:C0:T1:L0': devclass has changed:  devclass=0xd
Jun 11 03:00:19 bmhesx1 vmkernel: 206:12:55:02.532 cpu6:4102)<4>hpsa0: Device:C0:T0:L0 IllegalRequest. 
Jun 11 03:04:57 bmhesx1 vmkernel: 206:12:59:40.273 cpu2:4127)Config: 297: "VMOverheadGrowthLimit" = -1, Old Value: 0, (Status: 0x0)
Jun 11 03:04:59 bmhesx1 vmkernel: 206:12:59:42.009 cpu4:4128)Config: 297: "HostLocalSwapDirEnabled" = 0, Old Value: 0, (Status: 0x0)
Jun 11 03:05:08 bmhesx1 vmkernel: 206:12:59:51.264 cpu5:4128)Config: 297: "VMOverheadGrowthLimit" = 0, Old Value: -1, (Status: 0x0)
Jun 11 03:05:19 bmhesx1 vmkernel: 206:13:00:02.522 cpu10:32434)WARNING: ScsiScan: 535: Path 'vmhba1:C0:T1:L0': devclass has changed:  devclass=0xd
Jun 11 03:05:19 bmhesx1 vmkernel: 206:13:00:02.523 cpu10:32434)WARNING: ScsiScan: 535: Path 'vmhba2:C0:T0:L0': devclass has changed:  devclass=0xd
Jun 11 03:05:19 bmhesx1 vmkernel: 206:13:00:02.524 cpu3:32434)WARNING: ScsiScan: 535: Path 'vmhba1:C0:T0:L0': devclass has changed:  devclass=0xd
Jun 11 03:05:19 bmhesx1 vmkernel: 206:13:00:02.524 cpu3:32434)WARNING: ScsiScan: 535: Path 'vmhba2:C0:T1:L0': devclass has changed:  devclass=0xd
Jun 11 03:05:19 bmhesx1 vmkernel: 206:13:00:02.532 cpu5:4128)<4>hpsa0: Device:C0:T0:L0 IllegalRequest. 
Jun 11 03:10:19 bmhesx1 vmkernel: 206:13:05:02.522 cpu1:30490)WARNING: ScsiScan: 535: Path 'vmhba1:C0:T1:L0': devclass has changed:  devclass=0xd
Jun 11 03:10:19 bmhesx1 vmkernel: 206:13:05:02.523 cpu4:30490)WARNING: ScsiScan: 535: Path 'vmhba2:C0:T0:L0': devclass has changed:  devclass=0xd
Jun 11 03:10:19 bmhesx1 vmkernel: 206:13:05:02.524 cpu4:30490)WARNING: ScsiScan: 535: Path 'vmhba1:C0:T0:L0': devclass has changed:  devclass=0xd
Jun 11 03:10:19 bmhesx1 vmkernel: 206:13:05:02.524 cpu4:30490)WARNING: ScsiScan: 535: Path 'vmhba2:C0:T1:L0': devclass has changed:  devclass=0xd

Hostd:

Code: Alles auswählen

[2011-06-11 02:55:31.863 F55E4B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 02:55:57.738 F5789B90 verbose 'DvsTracker'] FetchSwitches: added 0 items
[2011-06-11 02:55:57.738 F5789B90 verbose 'DvsTracker'] FetchDVPortgroups: added 0 items
[2011-06-11 02:57:02.113 F5684B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 02:57:44.552 F5748B90 verbose 'DvsManager'] PersistAllDvsInfo called
[2011-06-11 02:58:32.323 F5748B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 02:59:28.913 F5ABFB90 verbose 'Proxysvc Req65647'] New proxy client TCP(local=127.0.0.1:51961, peer=127.0.0.1:80)
[2011-06-11 02:59:28.915 F5562B90 info 'Vmomi'] Activation [N5Vmomi10ActivationE:0x5bc94828] : Invoke done [waitForUpdates] on [vmodl.query.PropertyCollector:ha-property-collector]
[2011-06-11 02:59:28.915 F5562B90 verbose 'Vmomi'] Arg version:
"5486"
[2011-06-11 02:59:28.915 F5562B90 info 'Vmomi'] Throw vmodl.fault.RequestCanceled
[2011-06-11 02:59:28.915 F5562B90 info 'Vmomi'] Result:
(vmodl.fault.RequestCanceled) {
   dynamicType = <unset>,
   faultCause = (vmodl.MethodFault) null,
   msg = "",
}
[2011-06-11 03:00:02.573 F5789B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 03:00:02.587 F5684B90 info 'TaskManager' opID=6b7c7912-52] Task Created : haTask-ha-host-vim.HostSystem.acquireCimServicesTicket-4016898
[2011-06-11 03:00:02.595 F5684B90 verbose 'Cimsvc' opID=6b7c7912-52] Ticket issued for CIMOM version 1.0, user vpxuser
[2011-06-11 03:00:02.596 F5684B90 info 'TaskManager' opID=6b7c7912-52] Task Completed : haTask-ha-host-vim.HostSystem.acquireCimServicesTicket-4016898 Status success
[2011-06-11 03:00:03.744 F5D6AB90 verbose 'App'] Looking up object with name = "haTask-ha-host-vim.HostSystem.acquireCimServicesTicket-4016743" failed.
[2011-06-11 03:00:03.744 F5D6AB90 verbose 'App'] Looking up object with name = "haTask-ha-host-vim.HostSystem.acquireCimServicesTicket-4016743" failed.
[2011-06-11 03:00:57.797 F5789B90 verbose 'DvsTracker'] FetchSwitches: added 0 items
[2011-06-11 03:00:57.797 F5789B90 verbose 'DvsTracker'] FetchDVPortgroups: added 0 items
[2011-06-11 03:01:33.213 F5625B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 03:02:44.553 F5D6AB90 verbose 'DvsManager'] PersistAllDvsInfo called
[2011-06-11 03:03:03.464 F55E4B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 03:04:23.374 F5562B90 verbose 'FSVolumeProvider'] RefreshOneNasVolume called on 172.19.0.53:/share/ESXDatastore320_01
[2011-06-11 03:04:23.403 F63F9900 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4cd29e72-949985e4-49b2-d48564ca2ede
[2011-06-11 03:04:23.428 F5A7EB90 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4cd2db3c-ed4f5258-6865-d48564ca2edc
[2011-06-11 03:04:23.515 F5789B90 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4cd2db56-2513d4b6-b964-d48564ca2edc
[2011-06-11 03:04:23.545 F5D6AB90 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4cd2db67-d9a0cd62-c2d7-d48564ca2edc
[2011-06-11 03:04:23.638 F55E4B90 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4cd2db76-3c22c08c-abc6-d48564ca2edc
[2011-06-11 03:04:23.711 F5625B90 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4cd3c566-e571bb48-69a3-d48564ca12ee
[2011-06-11 03:04:23.745 F5562B90 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4cef657e-7645fd40-d95f-d48564ca2edc
[2011-06-11 03:04:23.824 F5684B90 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4d077c63-8c7c5160-4d40-d48564ca2edc
[2011-06-11 03:04:23.852 F5A7EB90 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4d9aff30-f4b2bec8-406e-d48564ca12ee
[2011-06-11 03:04:23.966 F55A3B90 verbose 'FSVolumeProvider'] RefreshOneVmfsVolume on /vmfs/volumes/4de770fa-49de66f0-56f6-d48564caa1b4
[2011-06-11 03:04:25.651 F5D6AB90 verbose 'ha-license-manager' opID=HB-host-41@76104-b8] Load: Loading existing file: /etc/vmware/license.cfg
[2011-06-11 03:04:25.666 F5D6AB90 verbose 'App' opID=HB-host-41@76104-b8] ha-license-manager:Validate -> Valid license detected for "VMware ESX Server 4.0" (lastError=0, desc.IsValid:Yes)
[2011-06-11 03:04:28.994 F63F9900 verbose 'Proxysvc Req65648'] New proxy client TCP(local=127.0.0.1:56967, peer=127.0.0.1:80)
[2011-06-11 03:04:28.995 F5625B90 info 'Vmomi'] Activation [N5Vmomi10ActivationE:0x5caddff0] : Invoke done [waitForUpdates] on [vmodl.query.PropertyCollector:ha-property-collector]
[2011-06-11 03:04:28.995 F5625B90 verbose 'Vmomi'] Arg version:
"5486"
[2011-06-11 03:04:28.995 F5625B90 info 'Vmomi'] Throw vmodl.fault.RequestCanceled
[2011-06-11 03:04:28.995 F5625B90 info 'Vmomi'] Result:
(vmodl.fault.RequestCanceled) {
   dynamicType = <unset>,
   faultCause = (vmodl.MethodFault) null,
   msg = "",
}
[2011-06-11 03:04:33.714 F5D6AB90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 03:04:55.687 F5D6AB90 verbose 'Proxysvc Req65649'] New proxy client SSL(TCP(local=172.19.2.202:49241, peer=172.19.2.192:443))
[2011-06-11 03:04:55.766 F5A7EB90 verbose 'ha-license-manager' opID=HB-host-41@76104-4] Load: Loading existing file: /etc/vmware/license.cfg
[2011-06-11 03:04:55.782 F5A7EB90 verbose 'App' opID=HB-host-41@76104-4] ha-license-manager:Validate -> Valid license detected for "VMware ESX Server 4.0" (lastError=0, desc.IsValid:Yes)
[2011-06-11 03:04:55.799 F5748B90 verbose 'Locale' opID=HB-host-41@76104-4] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
[2011-06-11 03:04:55.799 F5748B90 verbose 'Locale' opID=HB-host-41@76104-4] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
[2011-06-11 03:04:55.834 F55E4B90 verbose 'ha-license-manager' opID=HB-host-41@76104-4] Load: Loading existing file: /etc/vmware/license.cfg
[2011-06-11 03:04:55.841 F55E4B90 verbose 'ha-license-manager' opID=HB-host-41@76104-4] Load: Loading existing file: /etc/vmware/license.cfg
[2011-06-11 03:04:55.849 F55E4B90 verbose 'App' opID=HB-host-41@76104-4] ha-license-manager:Validate -> Valid license detected for "VMware ESX Server 4.0" (lastError=0, desc.IsValid:Yes)
[2011-06-11 03:04:55.856 F55E4B90 verbose 'Locale' opID=HB-host-41@76104-4] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
[2011-06-11 03:04:55.856 F55E4B90 verbose 'Locale' opID=HB-host-41@76104-4] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
[2011-06-11 03:04:55.903 F5A7EB90 verbose 'DvsTracker' opID=HB-host-41@76104-4] FetchSwitches: added 0 items
[2011-06-11 03:04:55.903 F5A7EB90 verbose 'DvsTracker' opID=HB-host-41@76104-4] FetchDVPortgroups: added 0 items
[2011-06-11 03:04:55.980 F5562B90 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4cd3c566-e571bb48-69a3-d48564ca12ee/BMHVRANGER/BMHVRANGER-flat.vmdk" : open successful (21) size = 42949672960, hd = 0. Type 3
[2011-06-11 03:04:55.980 F5562B90 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4cd3c566-e571bb48-69a3-d48564ca12ee/BMHVRANGER/BMHVRANGER-flat.vmdk" : closed.
[2011-06-11 03:04:55.991 F5562B90 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4cd3c566-e571bb48-69a3-d48564ca12ee/BMHVRANGER/BMHVRANGER_1-flat.vmdk" : open successful (21) size = 858993459200, hd = 0. Type 3
[2011-06-11 03:04:55.992 F5562B90 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4cd3c566-e571bb48-69a3-d48564ca12ee/BMHVRANGER/BMHVRANGER_1-flat.vmdk" : closed.
[2011-06-11 03:04:56.068 F63F9900 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4d077c63-8c7c5160-4d40-d48564ca2edc/BMHAUTWEB/BMHAUTWEB-flat.vmdk" : open successful (21) size = 37580963840, hd = 0. Type 3
[2011-06-11 03:04:56.069 F63F9900 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4d077c63-8c7c5160-4d40-d48564ca2edc/BMHAUTWEB/BMHAUTWEB-flat.vmdk" : closed.
[2011-06-11 03:04:56.152 F5789B90 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4cd2db56-2513d4b6-b964-d48564ca2edc/BMHMDECOM/BMHMDECOM-flat.vmdk" : open successful (21) size = 21474836480, hd = 0. Type 3
[2011-06-11 03:04:56.154 F5789B90 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4cd2db56-2513d4b6-b964-d48564ca2edc/BMHMDECOM/BMHMDECOM-flat.vmdk" : closed.
[2011-06-11 03:04:56.160 F5789B90 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4cd2db56-2513d4b6-b964-d48564ca2edc/BMHMDECOM/BMHMDECOM_1-flat.vmdk" : open successful (21) size = 42949672960, hd = 0. Type 3
[2011-06-11 03:04:56.161 F5789B90 info 'DiskLib' opID=HB-host-41@76104-4] DISKLIB-VMFS  : "/vmfs/volumes/4cd2db56-2513d4b6-b964-d48564ca2edc/BMHMDECOM/BMHMDECOM_1-flat.vmdk" : closed.
[2011-06-11 03:04:57.202 F5748B90 info 'TaskManager' opID=HB-host-41@76104-1f] Task Created : haTask--vim.SessionManager.updateMessage-4016989
[2011-06-11 03:04:57.203 F5748B90 info 'TaskManager' opID=HB-host-41@76104-1f] Task Completed : haTask--vim.SessionManager.updateMessage-4016989 Status success
[2011-06-11 03:04:57.208 F5ABFB90 info 'TaskManager' opID=HB-host-41@76104-1f] Task Created : haTask-ha-host-vim.HostSystem.updateManagementServerIp-4016990
[2011-06-11 03:04:57.209 F5ABFB90 info 'TaskManager' opID=HB-host-41@76104-1f] Task Completed : haTask-ha-host-vim.HostSystem.updateManagementServerIp-4016990 Status success
[2011-06-11 03:04:57.234 F5D6AB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
[2011-06-11 03:04:57.234 F5D6AB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
[2011-06-11 03:04:57.245 F5D6AB90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Created : haTask-ha-host-vim.option.OptionManager.updateValues-4016992
[2011-06-11 03:04:57.353 F5D6AB90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Completed : haTask-ha-host-vim.option.OptionManager.updateValues-4016992 Status success
[2011-06-11 03:04:57.394 F5684B90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Created : haTask-ha-root-pool-vim.ResourcePool.updateChildResourceConfiguration-4016993
[2011-06-11 03:04:57.395 F5684B90 info 'vm:/vmfs/volumes/4cd3c566-e571bb48-69a3-d48564ca12ee/BMHVRANGER/BMHVRANGER.vmx' opID=HB-host-41@76104-4c] State Transition (VM_STATE_ON -> VM_STATE_RECONFIGURING)
[2011-06-11 03:04:57.631 F5789B90 verbose 'vm:/vmfs/volumes/4cd3c566-e571bb48-69a3-d48564ca12ee/BMHVRANGER/BMHVRANGER.vmx'] No Upgrade required
[2011-06-11 03:04:57.658 F55E4B90 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:04:57.743 F5684B90 info 'vm:/vmfs/volumes/4cd3c566-e571bb48-69a3-d48564ca12ee/BMHVRANGER/BMHVRANGER.vmx' opID=HB-host-41@76104-4c] State Transition (VM_STATE_RECONFIGURING -> VM_STATE_ON)
[2011-06-11 03:04:57.743 F5625B90 verbose 'HostsvcPlugin'] Received state change for VM '352'
[2011-06-11 03:04:58.131 F5684B90 verbose 'vm:/vmfs/volumes/4cd3c566-e571bb48-69a3-d48564ca12ee/BMHVRANGER/BMHVRANGER.vmx' opID=HB-host-41@76104-4c] Time to gather config: 337 (msecs)
[2011-06-11 03:04:58.136 F5625B90 verbose 'Statssvc'] Adding vm 352 to poweredOnVms list
[2011-06-11 03:04:58.162 F5684B90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Completed : haTask-ha-root-pool-vim.ResourcePool.updateChildResourceConfiguration-4016993 Status success
[2011-06-11 03:04:58.163 F5ABFB90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Created : haTask-ha-root-pool-vim.ResourcePool.updateChildResourceConfiguration-4016995
[2011-06-11 03:04:58.164 F5ABFB90 info 'vm:/vmfs/volumes/4d077c63-8c7c5160-4d40-d48564ca2edc/BMHAUTWEB/BMHAUTWEB.vmx' opID=HB-host-41@76104-4c] State Transition (VM_STATE_ON -> VM_STATE_RECONFIGURING)
[2011-06-11 03:04:58.360 F5562B90 verbose 'vm:/vmfs/volumes/4d077c63-8c7c5160-4d40-d48564ca2edc/BMHAUTWEB/BMHAUTWEB.vmx'] No Upgrade required
[2011-06-11 03:04:58.420 F55E4B90 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:04:58.422 F5ABFB90 info 'vm:/vmfs/volumes/4d077c63-8c7c5160-4d40-d48564ca2edc/BMHAUTWEB/BMHAUTWEB.vmx' opID=HB-host-41@76104-4c] State Transition (VM_STATE_RECONFIGURING -> VM_STATE_ON)
[2011-06-11 03:04:58.422 F63F9900 verbose 'HostsvcPlugin'] Received state change for VM '368'
[2011-06-11 03:04:58.428 F5ABFB90 verbose 'vm:/vmfs/volumes/4d077c63-8c7c5160-4d40-d48564ca2edc/BMHAUTWEB/BMHAUTWEB.vmx' opID=HB-host-41@76104-4c] Time to gather config: 4 (msecs)
[2011-06-11 03:04:58.434 F63F9900 verbose 'Statssvc'] Adding vm 368 to poweredOnVms list
[2011-06-11 03:04:58.457 F5ABFB90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Completed : haTask-ha-root-pool-vim.ResourcePool.updateChildResourceConfiguration-4016995 Status success
[2011-06-11 03:04:58.458 F5A7EB90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Created : haTask-ha-root-pool-vim.ResourcePool.updateChildResourceConfiguration-4016997
[2011-06-11 03:04:58.458 F5A7EB90 info 'vm:/vmfs/volumes/4cd2db56-2513d4b6-b964-d48564ca2edc/BMHMDECOM/BMHMDECOM.vmx' opID=HB-host-41@76104-4c] State Transition (VM_STATE_ON -> VM_STATE_RECONFIGURING)
[2011-06-11 03:04:58.634 F55A3B90 verbose 'vm:/vmfs/volumes/4cd2db56-2513d4b6-b964-d48564ca2edc/BMHMDECOM/BMHMDECOM.vmx'] No Upgrade required
[2011-06-11 03:04:58.698 F5A7EB90 info 'vm:/vmfs/volumes/4cd2db56-2513d4b6-b964-d48564ca2edc/BMHMDECOM/BMHMDECOM.vmx' opID=HB-host-41@76104-4c] State Transition (VM_STATE_RECONFIGURING -> VM_STATE_ON)
[2011-06-11 03:04:58.698 F5625B90 verbose 'HostsvcPlugin'] Received state change for VM '416'
[2011-06-11 03:04:58.704 F5A7EB90 verbose 'vm:/vmfs/volumes/4cd2db56-2513d4b6-b964-d48564ca2edc/BMHMDECOM/BMHMDECOM.vmx' opID=HB-host-41@76104-4c] Time to gather config: 5 (msecs)
[2011-06-11 03:04:58.711 F5625B90 verbose 'Statssvc'] Adding vm 416 to poweredOnVms list
[2011-06-11 03:04:58.734 F5A7EB90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Completed : haTask-ha-root-pool-vim.ResourcePool.updateChildResourceConfiguration-4016997 Status success
[2011-06-11 03:04:58.737 F5789B90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Created : haTask-ha-compute-res-vim.ComputeResource.reconfigureEx-4016999
[2011-06-11 03:04:59.007 F5789B90 info 'ComputeResource' opID=HB-host-41@76104-4c] Updated local swap datastore policy: false
[2011-06-11 03:04:59.007 F5789B90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Completed : haTask-ha-compute-res-vim.ComputeResource.reconfigureEx-4016999 Status success
[2011-06-11 03:04:59.011 F55E4B90 warning 'PropertyCollector'] ComputeGUReq took 1739277 microSec
[2011-06-11 03:04:59.307 F5684B90 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:04:59.984 F5684B90 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:05:00.525 F5684B90 warning 'PropertyCollector'] ComputeGUReq took 1494257 microSec
[2011-06-11 03:05:00.564 F55E4B90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Created : haTask-ha-host-vim.option.OptionManager.updateValues-4017002
[2011-06-11 03:05:00.563 F5ABFB90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.1.eax' value '"disable"'
[2011-06-11 03:05:00.579 F5ABFB90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.1.ecx' value '"disable"'
[2011-06-11 03:05:00.580 F5ABFB90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.1.edx' value '"disable"'
[2011-06-11 03:05:00.581 F5ABFB90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.80000001.ecx' value '"disable"'
[2011-06-11 03:05:00.582 F5ABFB90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.80000001.edx' value '"disable"'
[2011-06-11 03:05:00.640 F5ABFB90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Completed : haTask-ha-host-vim.option.OptionManager.updateValues-4017002 Status success
[2011-06-11 03:05:00.641 F5625B90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Created : haTask-ha-host-vim.option.OptionManager.updateValues-4017003
[2011-06-11 03:05:00.866 F63F9900 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:05:01.571 F63F9900 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:05:02.030 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.val.1.eax' value '"0x00020651"'
[2011-06-11 03:05:02.034 F63F9900 warning 'PropertyCollector'] ComputeGUReq took 1450458 microSec
[2011-06-11 03:05:02.034 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.1.eax' value '"clobber"'
[2011-06-11 03:05:02.035 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.val.1.ecx' value '"0x0298e23f"'
[2011-06-11 03:05:02.036 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.1.ecx' value '"mask"'
[2011-06-11 03:05:02.037 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.val.1.edx' value '"0x8febfbff"'
[2011-06-11 03:05:02.038 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.1.edx' value '"mask"'
[2011-06-11 03:05:02.039 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.val.80000001.ecx' value '"0x00000001"'
[2011-06-11 03:05:02.039 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.80000001.ecx' value '"mask"'
[2011-06-11 03:05:02.040 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.val.80000001.edx' value '"0x28100800"'
[2011-06-11 03:05:02.041 F5625B90 info 'DictionaryOptionsProvider(Config.Defaults.)' opID=HB-host-41@76104-4c] Set called with key 'Config.Defaults.cpuidMask.mode.80000001.edx' value '"mask"'
[2011-06-11 03:05:02.042 F5625B90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Completed : haTask-ha-host-vim.option.OptionManager.updateValues-4017003 Status success
[2011-06-11 03:05:02.044 F5ABFB90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Created : haTask-ha-host-vim.HostSystem.updateSslThumbprintInfo-4017004
[2011-06-11 03:05:02.044 F5ABFB90 info 'TaskManager' opID=HB-host-41@76104-4c] Task Completed : haTask-ha-host-vim.HostSystem.updateSslThumbprintInfo-4017004 Status success
[2011-06-11 03:05:02.256 F55A3B90 info 'TaskManager' opID=HB-host-41@76104-50] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017005
[2011-06-11 03:05:02.273 F55A3B90 info 'TaskManager' opID=HB-host-41@76104-50] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017005 Status success
[2011-06-11 03:05:02.288 F5625B90 info 'TaskManager' opID=HB-host-41@76104-ab] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017006
[2011-06-11 03:05:02.308 F5625B90 info 'TaskManager' opID=HB-host-41@76104-ab] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017006 Status success
[2011-06-11 03:05:02.322 F5A7EB90 info 'TaskManager' opID=HB-host-41@76104-a0] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017007
[2011-06-11 03:05:02.343 F5A7EB90 info 'TaskManager' opID=HB-host-41@76104-a0] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017007 Status success
[2011-06-11 03:05:02.349 F5789B90 info 'TaskManager' opID=HB-host-41@76104-9b] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017008
[2011-06-11 03:05:02.368 F5789B90 info 'TaskManager' opID=HB-host-41@76104-9b] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017008 Status success
[2011-06-11 03:05:02.372 F5748B90 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:05:02.375 F55A3B90 info 'TaskManager' opID=HB-host-41@76104-2b] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017009
[2011-06-11 03:05:02.395 F55A3B90 info 'TaskManager' opID=HB-host-41@76104-2b] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017009 Status success
[2011-06-11 03:05:02.400 F5625B90 info 'TaskManager' opID=HB-host-41@76104-7d] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017010
[2011-06-11 03:05:02.825 F5625B90 info 'TaskManager' opID=HB-host-41@76104-7d] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017010 Status success
[2011-06-11 03:05:02.851 F5A7EB90 info 'TaskManager' opID=HB-host-41@76104-ee] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017011
[2011-06-11 03:05:02.901 F5A7EB90 info 'TaskManager' opID=HB-host-41@76104-ee] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017011 Status success
[2011-06-11 03:05:02.907 F5789B90 info 'TaskManager' opID=HB-host-41@76104-66] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017012
[2011-06-11 03:05:02.925 F5789B90 info 'TaskManager' opID=HB-host-41@76104-66] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017012 Status success
[2011-06-11 03:05:02.932 F55A3B90 info 'TaskManager' opID=HB-host-41@76104-63] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017013
[2011-06-11 03:05:02.951 F55A3B90 info 'TaskManager' opID=HB-host-41@76104-63] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017013 Status success
[2011-06-11 03:05:02.956 F5625B90 info 'TaskManager' opID=HB-host-41@76104-b9] Task Created : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017014
[2011-06-11 03:05:02.974 F5625B90 info 'TaskManager' opID=HB-host-41@76104-b9] Task Completed : haTask--vim.StorageResourceManager.ConfigureDatastoreIORMOnHost-4017014 Status success
[2011-06-11 03:05:03.103 F5748B90 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:05:03.564 F5748B90 warning 'PropertyCollector'] ComputeGUReq took 1498367 microSec
[2011-06-11 03:05:07.279 F5562B90 verbose 'ha-license-manager' opID=HB-host-41@76109-8b] Load: Loading existing file: /etc/vmware/license.cfg
[2011-06-11 03:05:07.294 F5562B90 verbose 'App' opID=HB-host-41@76109-8b] ha-license-manager:Validate -> Valid license detected for "VMware ESX Server 4.0" (lastError=0, desc.IsValid:Yes)
[2011-06-11 03:05:07.571 F55A3B90 verbose 'NetConfigProvider' opID=HB-host-41@76109-8b] FetchFn: List of pnics opted out
[2011-06-11 03:05:08.235 F55E4B90 info 'TaskManager' opID=HB-host-41@76109-39] Task Created : haTask-ha-host-vim.option.OptionManager.updateValues-4017016
[2011-06-11 03:05:08.364 F55E4B90 info 'TaskManager' opID=HB-host-41@76109-39] Task Completed : haTask-ha-host-vim.option.OptionManager.updateValues-4017016 Status success
[2011-06-11 03:05:08.609 F5ABFB90 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:05:09.284 F5ABFB90 verbose 'NetConfigProvider'] FetchFn: List of pnics opted out
[2011-06-11 03:05:09.743 F5ABFB90 warning 'PropertyCollector'] ComputeGUReq took 1479912 microSec
[2011-06-11 03:05:17.247 F5625B90 verbose 'ha-license-manager' opID=HB-host-41@76111-fa] Load: Loading existing file: /etc/vmware/license.cfg
[2011-06-11 03:05:17.261 F5625B90 verbose 'App' opID=HB-host-41@76111-fa] ha-license-manager:Validate -> Valid license detected for "VMware ESX Server 4.0" (lastError=0, desc.IsValid:Yes)
[2011-06-11 03:05:17.549 F63F9900 verbose 'NetConfigProvider' opID=HB-host-41@76111-fa] FetchFn: List of pnics opted out
[2011-06-11 03:05:27.257 F55A3B90 verbose 'ha-license-manager' opID=HB-host-41@76112-19] Load: Loading existing file: /etc/vmware/license.cfg
[2011-06-11 03:05:27.272 F55A3B90 verbose 'App' opID=HB-host-41@76112-19] ha-license-manager:Validate -> Valid license detected for "VMware ESX Server 4.0" (lastError=0, desc.IsValid:Yes)
[2011-06-11 03:05:57.858 F5ABFB90 verbose 'DvsTracker'] FetchSwitches: added 0 items
[2011-06-11 03:05:57.858 F5ABFB90 verbose 'DvsTracker'] FetchDVPortgroups: added 0 items
[2011-06-11 03:06:03.964 F5A7EB90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 03:07:34.214 F5748B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 03:07:44.554 F5D6AB90 verbose 'DvsManager'] PersistAllDvsInfo called
[2011-06-11 03:09:04.464 F5625B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
[2011-06-11 03:09:58.735 F5D6AB90 verbose 'Proxysvc Req65650'] New proxy client TCP(local=127.0.0.1:55450, peer=127.0.0.1:80)
[2011-06-11 03:09:58.736 F55A3B90 info 'Vmomi'] Activation [N5Vmomi10ActivationE:0x5d30aa48] : Invoke done [waitForUpdates] on [vmodl.query.PropertyCollector:ha-property-collector]


[Tschoergez]

hm, lässt sich kein fehler feststellen im vmkernel...
kannst du irgendne regelmäßigkeit feststellen, zu der die Abbrüche auftreten?

[JanP]

Hallo Jörg, danke dir fürs "durchforsten" meiner Logs.
Ich kein Muster erkannt. Diese Meldungen kommen übrigens seit der Installation des Clusters mehr oder weniger regelmäßig.
Ich habe gerade mal alle VM´s auf einen Host geschoben, mal schauen ob die beiden gelangweilten Hosts trotzdem Fehler bringen. Hoffe DRS lässt die VM´s auch auf dem einen Server

13.04. 03:20 Host 2
29.04. 00:28 Host 1
29.04. 02:21 Host 2
07.05. 15:18 Host 3
14.05. 17:03 Host 1
20.05. 04:33 Host 1
27.05. 01:24 Host 3
28.05. 07:00 Host 1 (07:00 ist Startzeit für ein Backup mit VRanger)
31.05. 15:26 Host 3
31.05. 22:00 Host 1
10.06. 21:32 Host 3
11.06. 03:04 Host 1

[Tschoergez]

Schau noch mal genau auf die Namenseinstellungen für alle Komponenten: Namensauflösung muss vorwärts und rückwärts mit langem und kurzem namen funktionieren.

Kann es sein, dass es sonstige "Hick-ups" im Netzwerk gibt?
Hast Du irgendein Monitoring, dass die Management-Consolen der ESX direkt anpingt während der Zeit?
(Um rauszukreigen, ob der Fehler eher am vCenter oder an den Hosts zu suchen ist)
Dabei fällt mir ein: ist Dein vCenter physikalisch oder virtuell? Wenn Virtuell, evtl. zu den Zeiten via DRS migriert worden?

Ansonsten bleibt wohl nur, den VMware Support einzuschalten, vllt. können die aus den Logs mehr rauslesen...

[JanP]

Das ganze läuft ohne DNS.
Die Namen/IP´s der Hosts sind in den hosts der esx-server selbst eingestellt. Ich habe die jetzt nochmal in die hosts der vcenter-server-vm eingetragen.
Das Netzwerk ist sonst clean. Die HP Procurce Management-Software meldet keine Fehler. DRS hat hier noch nichts migriert. Dazu ist die Auslastung viel zu gering.
Es läuft zeit kurzem die Software Fing Over-look die das Netzwerk alle 5 scannt/pingt. Aber die Fehler waren vorher schon vorhanden.

Ich werde das jetzt mal beobachten und dann bei Bedarf den VMware-Support damit beschäftigen.
Danke dir für deine Tipps!

MfG
Jan

[PeterDA]

Hallo Jan,
für mich scheint es ein DNS Problem zu sein. Wobei ich nicht verstehen kann warum du die Umgebung ohne DNS betreiben willst. Für den vCenter brauchst du ja eigentlich ein ADS und die geht ja bekanntermassen nicht ohne DNS.

Wenn du es trotzdem ohne probieren willst, musst du in die Host Datei der ESX un des vCenter alles manuell eintragen. Wichtig ist dabei, das du die langen und die kurzen DNS Namen einträgst.

Grus Peter

[JMcClane]

Hm, nach dem was ich so weiß sollte man keine Hosts-Dateien pflegen auf den ESX Servern in einer HA Umgebung. Denn HA pflegt die Namensauflösung selber um auch bei DNS-Ausfall noch zu funktionieren.

[PeterDA]

Ja aber wenn du kein DNS einsetzen willst dann must du das halt doch machen. Sonst gehen halt andere Dinge wieder nicht.....

Gruß Peter

[JanP]

Ich habe bewusst auf DNS/ADS verzichtet. Kurze und lange Namen in den Hosts sollten ausreichen. (So hieß es beim Kauf damals)
Die Namensauflösung funktioniert auch so unter allen beteiligten. Lediglich der 2008R2 welcher den Vcenter Server beherbergt hatte diese Einträge bisher nicht.
Jetzt schaue ich mal ob es was gebracht hat.

[JanP]

Namensauflösungs-einstellungen am VCenter Server waren wohl das problem.
Seit pflegen der hosts, keine Probleme bisher.
Dank an alle, Top Forum