VMware Cloud Community
aztechy
Contributor
Contributor

Input/output error (327689)

I keep getting this error whenever I manually clone a vm folder to another folder. Maybe someone has ran into this problem before?

"

Jun  2 04:21:38 Hostd: [2011-06-02 04:21:38.159 19F03B90 info 'DiskLib'] DISKLIB-LIB   : Failed to clone : Input/output error (327689)."


Here is the log:
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.312 19EC2B90 info 'Nfc'] file copy  (/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master.vmx -> /vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master.
Jun  2 04:19:43 vmx) by 'root'
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.378 19F03B90 info 'DiskLib'] DISKLIB-LINK  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master.vmdk" : creation successful.
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.379 19F03B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : open successful (17) size = 4294967296, hd = 0. Type 3
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.404 19F03B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : closed.
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.405 19F03B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : open successful (16) size = 4294967296, hd = 2097733. Type 3
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.406 19F03B90 info 'DiskLib'] DISKLIB-DSCPTR: Opened [0]: "Xp Pro CPU Master-flat.vmdk" (0x10)
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.406 19F03B90 info 'DiskLib'] DISKLIB-LINK  : Opened '/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master.vmdk' (0x10): vmfs, 8388608 sectors / 4 GB.
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.406 19F03B90 info 'DiskLib'] DISKLIB-LIB   : Opened "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master.vmdk" (flags 0x10).
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.410 19F03B90 info 'DiskLib'] DISKLIB-DDB   : "longContentID" = "4ce0ab60f151888a6514ac0bcad4a696" (was "541172300f778fdc0f713558f06da437")
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.577 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 16777216, max 0
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.720 19F85B90 verbose 'DatastoreBrowser'] 4a2e0740-6d148898-cbd6-001871e37282-datastorebrowser::Search Path = [datastore1] TESTING Spec = (vim.host.DatastoreBrowser.SearchSpec) {    dynamicType = <unset>,   
Jun  2 04:19:43   query = (vim.host.DatastoreBrowser.Query) [       (vim.host.DatastoreBrowser.FolderQuery) {          dynamicType = <unset>,        },        (vim.host.DatastoreBrowser.FloppyImageQuery) {          dynamicType = <unset>,        },        (vim.host.Datast
Jun  2 04:19:43 oreBrowser.IsoImageQuery) {          dynamicType = <unset>,        },        (vim.host.DatastoreBrowser.VmConfigQuery) {          dynamicType = <unset>,           filter = (vim.host.DatastoreBrowser.VmConfigQuery.Filter) null,           details = (vim.hos
Jun  2 04:19:43 t.DatastoreBrowser.VmConfigQuery.Details) null,        },        (vim.host.DatastoreBrowser.TemplateVmConfigQuery) {          dynamicType = <unset>,           filter = (vim.host.DatastoreBrowser.VmConfigQuery.Filter) null,           details = (vim.host.Da
Jun  2 04:19:43 tastoreBrowser.VmConfigQuery.Details) null,        },        (vim.host.DatastoreBrowser.VmLogQuery) {          dynamicType = <unset>,        },        (vim.host.DatastoreBrowser.Vm
Jun  2 04:19:43 Hostd: 
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.721 19F85B90 verbose 'DatastoreBrowser'] 4a2e0740-6d148898-cbd6-001871e37282-datastorebrowser::SearchInt
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.721 19F85B90 verbose 'DatastoreBrowser'] 4a2e0740-6d148898-cbd6-001871e37282-datastorebrowser::GetLocalpathFromDatastorepath
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.721 19F85B90 verbose 'DatastoreBrowser'] 4a2e0740-6d148898-cbd6-001871e37282-datastorebrowser::Verify
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.816 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 50331648, max 0
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.817 19F85B90 info 'DiskLib'] DISKLIB-DSCPTR: descriptor above max size: 4294967296
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.818 19F85B90 info 'DiskLib'] DISKLIB-LINK  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : failed to open (The file specified is not a virtual disk).  
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.836 19F85B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : open successful (17) size = 4294967296, hd = 0. Type 3
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.837 19F85B90 verbose 'App'] [Search::GetInfo] Successfully opened disk: /vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master.vmdk
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.842 19F85B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : open successful (21) size = 4294967296, hd = 0. Type 3
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.842 19F85B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : closed.
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.843 19F85B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : closed.
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.844 19F85B90 verbose 'DatastoreBrowser'] DatastoreBrowserImpl::PopulateSearchResult: File: '/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master.vmx' is owned by user 'root'
Jun  2 04:19:43 Hostd: [2011-06-02 04:19:43.844 19F85B90 verbose 'DatastoreBrowser'] DatastoreBrowserImpl::PopulateSearchResult: File: '/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master.vmdk' is owned by user 'root'
Jun  2 04:19:44 Hostd: [2011-06-02 04:19:44.887 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 100663296, max 0
Jun  2 04:19:45 Hostd: [2011-06-02 04:19:45.698 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 134217728, max 0
Jun  2 04:19:46 Hostd: [2011-06-02 04:19:46.723 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 184549376, max 0
Jun  2 04:19:47 Hostd: [2011-06-02 04:19:47.543 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 218103808, max 0
Jun  2 04:19:48 Hostd: [2011-06-02 04:19:48.619 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 268435456, max 0
Jun  2 04:19:49 Hostd: [2011-06-02 04:19:49.405 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 301989888, max 0
Jun  2 04:19:50 Hostd: [2011-06-02 04:19:50.891 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 352321536, max 0
Jun  2 04:19:51 Hostd: [2011-06-02 04:19:51.653 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 402653184, max 0
Jun  2 04:19:52 Hostd: [2011-06-02 04:19:52.417 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 436207616, max 0
Jun  2 04:19:53 Hostd: [2011-06-02 04:19:53.862 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 486539264, max 0
Jun  2 04:19:54 Hostd: [2011-06-02 04:19:54.580 19F85B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:19:54 Hostd: [2011-06-02 04:19:54.581 19F85B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:19:54 Hostd: [2011-06-02 04:19:54.582 19F85B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:19:54 Hostd: [2011-06-02 04:19:54.582 19F85B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:19:54 Hostd: [2011-06-02 04:19:54.803 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 520093696, max 0
Jun  2 04:19:55 Hostd: [2011-06-02 04:19:55.947 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 570425344, max 0
Jun  2 04:19:56 Hostd: [2011-06-02 04:19:56.705 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 603979776, max 0
Jun  2 04:19:57 Hostd: [2011-06-02 04:19:57.861 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 654311424, max 0
Jun  2 04:19:58 Hostd: [2011-06-02 04:19:58.477 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 687865856, max 0
Jun  2 04:19:59 Hostd: [2011-06-02 04:19:59.971 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 738197504, max 0
Jun  2 04:20:00 Hostd: [2011-06-02 04:20:00.788 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 788529152, max 0
Jun  2 04:20:01 Hostd: [2011-06-02 04:20:01.768 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 822083584, max 0
Jun  2 04:20:03 Hostd: [2011-06-02 04:20:03.208 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 872415232, max 0
Jun  2 04:20:03 Hostd: [2011-06-02 04:20:03.949 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 905969664, max 0
Jun  2 04:20:04 Hostd: [2011-06-02 04:20:04.813 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 956301312, max 0
Jun  2 04:20:05 Hostd: [2011-06-02 04:20:05.674 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 989855744, max 0
Jun  2 04:20:07 Hostd: [2011-06-02 04:20:07.084 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1040187392, max 0
Jun  2 04:20:07 Hostd: [2011-06-02 04:20:07.467 117F0B90 verbose 'DatastoreBrowser'] 4a2e0740-6d148898-cbd6-001871e37282-datastorebrowser::Search Path = [datastore1] ISO3/Xp Pro CPU87 Spec = (vim.host.DatastoreBrowser.SearchSpec) {    dynamicType = <
Jun  2 04:20:07 unset>,     query = (vim.host.DatastoreBrowser.Query) [       (vim.host.DatastoreBrowser.FolderQuery) {          dynamicType = <unset>,        },        (vim.host.DatastoreBrowser.FloppyImageQuery) {          dynamicType = <unset>,        },        (vim.h
Jun  2 04:20:07 ost.DatastoreBrowser.IsoImageQuery) {          dynamicType = <unset>,        },        (vim.host.DatastoreBrowser.VmConfigQuery) {          dynamicType = <unset>,           filter = (vim.host.DatastoreBrowser.VmConfigQuery.Filter) null,           details 
Jun  2 04:20:07 = (vim.host.DatastoreBrowser.VmConfigQuery.Details) null,        },        (vim.host.DatastoreBrowser.TemplateVmConfigQuery) {          dynamicType = <unset>,           filter = (vim.host.DatastoreBrowser.VmConfigQuery.Filter) null,           details = (v
Jun  2 04:20:07 im.host.DatastoreBrowser.VmConfigQuery.Details) null,        },        (vim.host.DatastoreBrowser.VmLogQuery) {          dynamicType = <unset>,        },        (vim.host.Datastore
Jun  2 04:20:07 Hostd: 
Jun  2 04:20:07 Hostd: [2011-06-02 04:20:07.468 117F0B90 verbose 'DatastoreBrowser'] 4a2e0740-6d148898-cbd6-001871e37282-datastorebrowser::SearchInt
Jun  2 04:20:07 Hostd: [2011-06-02 04:20:07.468 117F0B90 verbose 'DatastoreBrowser'] 4a2e0740-6d148898-cbd6-001871e37282-datastorebrowser::GetLocalpathFromDatastorepath
Jun  2 04:20:07 Hostd: [2011-06-02 04:20:07.728 117F0B90 verbose 'DatastoreBrowser'] 4a2e0740-6d148898-cbd6-001871e37282-datastorebrowser::Verify
Jun  2 04:20:07 Hostd: [2011-06-02 04:20:07.958 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1073741824, max 0
Jun  2 04:20:09 Hostd: [2011-06-02 04:20:09.186 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1124073472, max 0
Jun  2 04:20:09 Hostd: [2011-06-02 04:20:09.466 117F0B90 info 'DiskLib'] DISKLIB-DSCPTR: descriptor above max size: 4294967296
Jun  2 04:20:09 Hostd: [2011-06-02 04:20:09.466 117F0B90 info 'DiskLib'] DISKLIB-LINK  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master-flat.vmdk" : failed to open (The file specified is not a virtual disk).  
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.565 117F0B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master-flat.vmdk" : open successful (17) size = 4294967296, hd = 0. Type 3
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.566 117F0B90 verbose 'App'] [Search::GetInfo] Successfully opened disk: /vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master.vmdk
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.586 117F0B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master-flat.vmdk" : open successful (21) size = 4294967296, hd = 0. Type 3
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.586 117F0B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master-flat.vmdk" : closed.
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.587 117F0B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master-flat.vmdk" : closed.
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.588 117F0B90 verbose 'DatastoreBrowser'] DatastoreBrowserImpl::PopulateSearchResult: File: '/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master.vmx' is owned by user 'root'
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.589 117F0B90 verbose 'DatastoreBrowser'] DatastoreBrowserImpl::PopulateSearchResult: File: '/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master.vmdk' is owned by user 'root
Jun  2 04:20:10 '
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.648 117F0B90 verbose 'DatastoreBrowser'] DatastoreBrowserImpl::PopulateSearchResult: File: '/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master.vmxf' is owned by user 'root
Jun  2 04:20:10 '
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.649 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1174405120, max 0
Jun  2 04:20:10 Hostd: [2011-06-02 04:20:10.652 117F0B90 verbose 'DatastoreBrowser'] DatastoreBrowserImpl::PopulateSearchResult: File: '/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master.vmsd' is owned by user 'root
Jun  2 04:20:10 '
Jun  2 04:20:11 Hostd: [2011-06-02 04:20:11.481 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1207959552, max 0
Jun  2 04:20:12 Hostd: [2011-06-02 04:20:12.686 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1258291200, max 0
Jun  2 04:20:13 Hostd: [2011-06-02 04:20:13.399 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1291845632, max 0
Jun  2 04:20:14 Hostd: [2011-06-02 04:20:14.320 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1342177280, max 0
Jun  2 04:20:14 Hostd: [2011-06-02 04:20:14.652 19CCCB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:20:14 Hostd: [2011-06-02 04:20:14.652 19CCCB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:20:14 Hostd: [2011-06-02 04:20:14.654 19CCCB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:20:14 Hostd: [2011-06-02 04:20:14.654 19CCCB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:20:15 Hostd: [2011-06-02 04:20:15.258 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1375731712, max 0
Jun  2 04:20:16 Hostd: [2011-06-02 04:20:16.717 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1426063360, max 0
Jun  2 04:20:17 Hostd: [2011-06-02 04:20:17.697 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1476395008, max 0
Jun  2 04:20:18 Hostd: [2011-06-02 04:20:18.466 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1509949440, max 0
Jun  2 04:20:19 Hostd: [2011-06-02 04:20:19.431 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1560281088, max 0
Jun  2 04:20:19 Hostd: [2011-06-02 04:20:19.560 117AFB90 verbose 'ResourcePool ha-root-pool'] Root pool capacity changed from 7514MHz/9894MB to 7514MHz/9895MB
Jun  2 04:20:20 Hostd: [2011-06-02 04:20:20.486 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1593835520, max 0
Jun  2 04:20:21 Hostd: [2011-06-02 04:20:21.586 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1644167168, max 0
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x4100050abac0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x410005079480) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x4100050441c0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x41000503cac0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x410005075080) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x4100050b50c0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x4100050b0bc0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x4100050aa1c0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.906 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x4100050423c0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x41000514c4c0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x41000507f780) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x410005155ac0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x41000501d580) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.948 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x410005072b80) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 Hostd: [2011-06-02 04:20:21.674 19F03B90 info 'DiskLib'] DISKLIB-VMFS :CopyData '/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk' : failed to move data (Input/output error:0x50009).
Jun  2 04:20:21 vmkernel: 0:00:36:44.949 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.949 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x41000514e0c0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 Hostd: [2011-06-02 04:20:21.674 19F03B90 info 'DiskLib'] DISKLIB-LIB   : DiskLib_Clone: Could not perform clone using vmkernel data mover. Falling back to non-accelerated clone. Input/output error
Jun  2 04:20:21 vmkernel: 0:00:36:44.949 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.949 cpu1:8666)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x41000514ccc0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.949 cpu1:8666)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:20:21 vmkernel: 0:00:36:44.951 cpu0:5090)FS3DM: 1595: status I/O error copying 16777216 bytes from file offset 1644167168 to file offset 1644167168, bytesTransferred = 0 extentsTransferred: 0
Jun  2 04:20:21 Hostd: [2011-06-02 04:20:21.688 19F03B90 info 'DiskLib'] DISKLIB-DDB   : "longContentID" = "1a97a98d5ba3628e938a5a02a71d9937" (was "4ce0ab60f151888a6514ac0bcad4a696")
Jun  2 04:20:21 Hostd: [2011-06-02 04:20:21.753 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 512, max 8388608
Jun  2 04:20:23 Hostd: [2011-06-02 04:20:23.501 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 83968, max 8388608
Jun  2 04:20:25 Hostd: [2011-06-02 04:20:25.640 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 167936, max 8388608
Jun  2 04:20:28 Hostd: [2011-06-02 04:20:28.661 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 251904, max 8388608
Jun  2 04:20:28 Hostd: [2011-06-02 04:20:28.891 1176EB90 verbose 'vm:/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/Xp Pro CPU6/Xp Pro CPU Master.vmx'] Actual VM overhead: 110596096 bytes
Jun  2 04:20:28 Hostd: [2011-06-02 04:20:28.893 1176EB90 verbose 'Vmsvc'] RefreshVms updated overhead for 1 VM
Jun  2 04:20:31 Hostd: [2011-06-02 04:20:31.197 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 335872, max 8388608
Jun  2 04:20:33 Hostd: [2011-06-02 04:20:33.856 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 419840, max 8388608
Jun  2 04:20:34 Hostd: [2011-06-02 04:20:34.741 1176EB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:20:34 Hostd: [2011-06-02 04:20:34.742 1176EB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:20:34 Hostd: [2011-06-02 04:20:34.743 1176EB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:20:34 Hostd: [2011-06-02 04:20:34.743 1176EB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:20:36 Hostd: [2011-06-02 04:20:36.277 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 503808, max 8388608
Jun  2 04:20:38 Hostd: [2011-06-02 04:20:38.981 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 587264, max 8388608
Jun  2 04:20:41 Hostd: [2011-06-02 04:20:41.663 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 671232, max 8388608
Jun  2 04:20:41 Hostd: [2011-06-02 04:20:41.891 1176EB90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root
Jun  2 04:20:42 Hostd: [2011-06-02 04:20:42.525 117F0B90 verbose 'DvsTracker'] FetchDVPortgroups: added 0 items
Jun  2 04:20:44 Hostd: [2011-06-02 04:20:44.527 19CCCB90 verbose 'vm:/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/Xp Pro CPU83/Xp Pro CPU Master.vmx'] Updating current heartbeatStatus: yellow
Jun  2 04:20:44 Hostd: [2011-06-02 04:20:44.727 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 755200, max 8388608
Jun  2 04:20:47 Hostd: [2011-06-02 04:20:47.029 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 839168, max 8388608
Jun  2 04:20:49 Hostd: [2011-06-02 04:20:49.660 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 923136, max 8388608
Jun  2 04:20:51 Hostd: [2011-06-02 04:20:51.461 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1007104, max 8388608
Jun  2 04:20:53 Hostd: [2011-06-02 04:20:53.806 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1090560, max 8388608
Jun  2 04:20:54 Hostd: [2011-06-02 04:20:54.917 19E81B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:20:54 Hostd: [2011-06-02 04:20:54.918 19E81B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:20:54 Hostd: [2011-06-02 04:20:54.919 19E81B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:20:54 Hostd: [2011-06-02 04:20:54.919 19E81B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:20:56 Hostd: [2011-06-02 04:20:56.435 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1174528, max 8388608
Jun  2 04:20:59 Hostd: [2011-06-02 04:20:59.158 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1258496, max 8388608
Jun  2 04:21:01 Hostd: [2011-06-02 04:21:01.578 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1342464, max 8388608
Jun  2 04:21:04 Hostd: [2011-06-02 04:21:04.453 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1426432, max 8388608
Jun  2 04:21:04 Hostd: [2011-06-02 04:21:04.528 19F44B90 verbose 'vm:/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/Xp Pro CPU83/Xp Pro CPU Master.vmx'] Updating current heartbeatStatus: green
Jun  2 04:21:07 Hostd: [2011-06-02 04:21:07.079 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1510400, max 8388608
Jun  2 04:21:08 Hostd: [2011-06-02 04:21:08.756 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1593856, max 8388608
Jun  2 04:21:08 Hostd: [2011-06-02 04:21:08.772 19EC2B90 verbose 'App'] Looking up object with name = "haTask--vim.FileManager.copy-278" failed.
Jun  2 04:21:08 Hostd: [2011-06-02 04:21:08.772 19EC2B90 verbose 'PropertyCollector'] GetPropertyProvider failed for haTask--vim.FileManager.copy-278
Jun  2 04:21:08 Hostd: [2011-06-02 04:21:08.900 19E81B90 verbose 'vm:/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/Xp Pro CPU74/Xp Pro CPU Master.vmx'] Actual VM overhead: 116338688 bytes
Jun  2 04:21:08 Hostd: [2011-06-02 04:21:08.901 19E81B90 verbose 'Vmsvc'] RefreshVms updated overhead for 1 VM
Jun  2 04:21:10 Hostd: [2011-06-02 04:21:10.771 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1677824, max 8388608
Jun  2 04:21:13 Hostd: [2011-06-02 04:21:13.076 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1761792, max 8388608
Jun  2 04:21:14 Hostd: [2011-06-02 04:21:14.600 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1845760, max 8388608
Jun  2 04:21:15 Hostd: [2011-06-02 04:21:15.066 117AFB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:21:15 Hostd: [2011-06-02 04:21:15.066 117AFB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:21:15 Hostd: [2011-06-02 04:21:15.067 117AFB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:21:15 Hostd: [2011-06-02 04:21:15.068 117AFB90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:21:16 Hostd: [2011-06-02 04:21:16.948 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 1929728, max 8388608
Jun  2 04:21:19 Hostd: [2011-06-02 04:21:19.179 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2013696, max 8388608
Jun  2 04:21:22 Hostd: [2011-06-02 04:21:22.220 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2097152, max 8388608
Jun  2 04:21:23 Hostd: [2011-06-02 04:21:23.741 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2181120, max 8388608
Jun  2 04:21:24 Hostd: [2011-06-02 04:21:24.896 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2265088, max 8388608
Jun  2 04:21:26 Hostd: [2011-06-02 04:21:26.037 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2349056, max 8388608
Jun  2 04:21:27 Hostd: [2011-06-02 04:21:27.177 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2433024, max 8388608
Jun  2 04:21:28 Hostd: [2011-06-02 04:21:28.325 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2516992, max 8388608
Jun  2 04:21:28 Hostd: [2011-06-02 04:21:28.904 117AFB90 verbose 'vm:/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/Xp Pro CPU2/Xp Pro CPU Master.vmx'] Actual VM overhead: 104693760 bytes
Jun  2 04:21:28 Hostd: [2011-06-02 04:21:28.908 117AFB90 verbose 'Vmsvc'] RefreshVms updated overhead for 1 VM
Jun  2 04:21:29 Hostd: [2011-06-02 04:21:29.492 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2600960, max 8388608
Jun  2 04:21:30 Hostd: [2011-06-02 04:21:30.617 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2684416, max 8388608
Jun  2 04:21:31 Hostd: [2011-06-02 04:21:31.746 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2768384, max 8388608
Jun  2 04:21:32 Hostd: [2011-06-02 04:21:32.870 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2852352, max 8388608
Jun  2 04:21:34 Hostd: [2011-06-02 04:21:34.002 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 2936320, max 8388608
Jun  2 04:21:35 Hostd: [2011-06-02 04:21:35.129 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 3020288, max 8388608
Jun  2 04:21:35 Hostd: [2011-06-02 04:21:35.572 19F44B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:21:35 Hostd: [2011-06-02 04:21:35.572 19F44B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:21:35 Hostd: [2011-06-02 04:21:35.573 19F44B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.label' expected in module 'enum'.
Jun  2 04:21:35 Hostd: [2011-06-02 04:21:35.574 19F44B90 verbose 'Locale'] Default resource used for 'host.SystemIdentificationInfo.IdentifierType.AssetTag.summary' expected in module 'enum'.
Jun  2 04:21:36 Hostd: [2011-06-02 04:21:36.255 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 3104256, max 8388608
Jun  2 04:21:37 Hostd: [2011-06-02 04:21:37.447 19F03B90 info 'Libs'] [NFC DEBUG] Clone progress cb: Current 3187712, max 8388608
Jun  2 04:21:37 vmkernel: 0:00:38:01.200 cpu2:10559)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x4100050b22c0) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:21:37 vmkernel: 0:00:38:01.200 cpu2:10559)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:21:37 vmkernel: 0:00:38:01.200 cpu2:10559)ScsiDeviceToken: 289: Sync IO 0x2a to device "mpx.vmhba2:C0:T0:L0" failed: I/O error H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:21:37 vmkernel: 0:00:38:01.200 cpu3:4156)BC: 2940: Failed to flush 128 buffers of size 8192 each for object 'Xp Pro CPU Master-flat.vmdk' f530 28 3 4a2e0740 6d148898 1800cbd6 8272e371 25801744 1f3 0 0 0 0 0: I/O error
Jun  2 04:21:37 vmkernel: 0:00:38:01.237 cpu2:8880)NMP: nmp_CompleteCommandForPath: Command 0x2a (0x410005079680) to NMP device "mpx.vmhba2:C0:T0:L0" failed on physical path "vmhba2:C0:T0:L0" H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:21:37 Hostd: [2011-06-02 04:21:37.960 19F03B90 info 'DiskLib'] DISKLIB-LIB   : RWv failed ioId: #10535 (327689) (9) .
Jun  2 04:21:37 vmkernel: 0:00:38:01.237 cpu2:8880)ScsiDeviceIO: 747: Command 0x2a to device "mpx.vmhba2:C0:T0:L0" failed H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:21:37 Hostd: [2011-06-02 04:21:37.961 19F03B90 info 'DiskLib'] DISKLIB-LIB   : Write error: sector 3214336: Input/output error (327689)
Jun  2 04:21:37 vmkernel: 0:00:38:01.237 cpu2:8880)ScsiDeviceToken: 289: Sync IO 0x2a to device "mpx.vmhba2:C0:T0:L0" failed: I/O error H:0x0 D:0x2 P:0x0 Valid sense data: 0x4 0x44 0x0.
Jun  2 04:21:37 vmkernel: 0:00:38:01.237 cpu1:4156)BC: 2940: Failed to flush 56 buffers of size 8192 each for object 'Xp Pro CPU Master-flat.vmdk' f530 28 3 4a2e0740 6d148898 1800cbd6 8272e371 25801744 1f3 0 0 0 0 0: I/O error
Jun  2 04:21:38 Hostd: [2011-06-02 04:21:38.038 19F03B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : closed.
Jun  2 04:21:38 Hostd: [2011-06-02 04:21:38.047 19F03B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : open successful (17) size = 4294967296, hd = 0. Type 3
Jun  2 04:21:38 Hostd: [2011-06-02 04:21:38.048 19F03B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Master-flat.vmdk" : closed.
Jun  2 04:21:38 Hostd: [2011-06-02 04:21:38.159 19F03B90 info 'DiskLib'] DISKLIB-LIB   : Failed to clone : Input/output error (327689).
Jun  2 04:21:38 Hostd: [2011-06-02 04:21:38.159 19F03B90 info 'Libs'] [NFC DEBUG] NfcFileClone: copy from /vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master.vmdk -> /vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/
Jun  2 04:21:38 TESTING/Xp Pro CPU Master.vmdk failed.
Jun  2 04:21:38 Hostd: [2011-06-02 04:21:38.224 19F03B90 info 'DiskLib'] DISKLIB-VMFS  : "/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master-flat.vmdk" : closed.
Jun  2 04:21:38 Hostd: [2011-06-02 04:21:38.225 19F03B90 error 'Nfc'] file copy  (/vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/ISO3/Xp Pro CPU87/Xp Pro CPU Master.vmdk -> /vmfs/volumes/4a2e0740-6d148898-cbd6-001871e37282/TESTING/Xp Pro CPU Maste
Jun  2 04:21:38 r.vmdk) by 'root'
Jun  2 04:21:38 Hostd: [2011-06-02 04:21:38.225 19F03B90 info 'TaskManager'] Task Completed : haTask--vim.FileManager.copy-330 Status error
Reply
0 Kudos
6 Replies
FranckRookie
Leadership
Leadership

Hi Aztechy,

The first error message I found in your log is:

  • ".../Xp Pro CPU Master-flat.vmdk" : failed to open (The file specified is not a virtual disk)

This could be due to a corrupted descriptor file. Have a look at the following KB if it can help:

Good luck.

Regards

Franck

Reply
0 Kudos
AndreTheGiant
Immortal
Immortal

There are some errors in the storage part.

Could be related to some kind of failures on  disks or controller.

See also: http://kb.vmware.com/kb/289902

Andre

Andrew | http://about.me/amauro | http://vinfrastructure.it/ | @Andrea_Mauro
aztechy
Contributor
Contributor

Thank you very much! I will check back to see if anyone else has any solutions. In the mean time I'll be testing the drives.

Reply
0 Kudos
aztechy
Contributor
Contributor

Ok attached is a screenshot of the "Storage Path" view in the ESXi reports graph. The large spikes are when cloning the VMs (copying the folders) and the drop is when it throws the error. I have replaced the drives. I have a BBWC on the RAID card. The BBWC is 1 year old. Could that be a sign of a bad BBWC?

Thanks everyone for your help!

Reply
0 Kudos
AndreTheGiant
Immortal
Immortal

Latency is high... but not huge... it does not explain the errors.

Check if the battery is working and if the controller cache policy is set to write back.

Also check for firmware upgrade.

Andre

Andrew | http://about.me/amauro | http://vinfrastructure.it/ | @Andrea_Mauro
aztechy
Contributor
Contributor

When I replaced drive 1 in the RAID 1,  it started working for a couple days. Do you think the other drive is bad too? I don't think the write cache setting could have changed on its own. The battery is giving lower voltage than what it should be. Should I try putting a new drive into drive 0?

Thanks for your help

Reply
0 Kudos