Moin,
habe mal die Eventlogs vom Server durchgesehen. Nichts auffälliges gefunden und schon gar nicht zu dem Zeitpunkt als der Restore fehlschlug. Scheint der Server gar nicht mitzubekommen. Ein separates "Client-Restore-Log" habe ich auf dem Server auch nicht gefunden. Also zurück zum Client...
Martin, wie gesagt, Netzwerkprobleme kann man wohl ausschließen, da ich ca. 10 Min. lang Daten von Server in die PE-Umgebung des Clients kopiert habe - sogar auf die C:-Partition, die der Restore Wizard korrekt angelegt hat. Bin aber ein Stück weiter gekommen, vielleicht auch für andere interessant. In mehreren US-Foren zum WHS wird dasselbe Problem behandelt, was ich auch habe, nur leider hat noch keiner eine Lösung gefunden, alle sind nur stingsauer auf MS. Allen Fehlern gemeinsam sind die letzten ca. 10 Zeilen im "WindowsServerPCRestore.log" (s.u.) auf dem Client. (Liegt auf dem Client auf X: während des Restores, kann man sich z.B. auf eine Servefreigabe kopieren.)
FSCTL_LOCK_VOLUME failed with 5... heißt wohl soviel wie: das Volume kann für den exklusiven Zugriff nicht gelockt werden. Das Problem tritt offensichtlich immer dann auf, wenn auf der Platte mehrere Partitionen vorhanden sind, wie bei mir: 1. 100MB System, 2. 100GB Windows, 3. Rest Daten. Leider haben alle meine Clients mehrere Partitionen auf der 1. Platte bzw. soger mehrere Platten im System. Das wird dann wohl nichts mit dem WHS und Clients (zurück)sichern. Das mit dem Umbau der Platte in einen anderen Client werde ich nicht machen, da es mir zu aufwendig ist, würde nach meinen Erkenntnissen auch nichts bringen. Der Client wird jetzt neu installiert. Schade. Habe jetzt mind. 30h mit dieser Problematik verbracht. Die Neuinstallation währe in einem Bruchteil der Zeit erledigt gewesen. Falls noch jemand eine Idee hat - gerne.
Dies nur als Warnung an alle, die sich auf Client-Restores verlassen: Probiert es unbedingt vorher aus - bevor ihr drauf angewiesen seit.
WindowsServerPCRestore.log
[09/30/2013 20:26:37 5b0] WSAStartup returned 0
[09/30/2013 20:26:37 5b0] Client Ipv6 address fe80::35c7:9b83:dee1:eec0
[09/30/2013 20:26:37 5b0] Client Ipv4 address 192.168.0.126
[09/30/2013 20:26:37 5b0] Start decrypting password
[09/30/2013 20:26:37 5b0] Calling m_Restore.DisconnectServer
[09/30/2013 20:26:37 5b0] m_Restore.DisconnectServer OK
[09/30/2013 20:26:37 5b0] Calling m_Restore.RequestParseServerXML
[09/30/2013 20:26:37 5b0] Waiting for completion callback
[09/30/2013 20:26:37 5b4] Getting server XML from url =
HTTP://HWHOMEES:80/Connect/default.aspx ... erinfo.xml
[09/30/2013 20:26:37 5b4] HTTP code = 200
[09/30/2013 20:26:37 5b4] Admin Name = Administrator, Password Hint = , Server Name = HWHOMEES
[09/30/2013 20:26:37 5b4] PASS :RequestCompleteHandler::Completed succeeded (at func: Request completed, backup\pc\client\homeservermanager\homeservermanager.cpp (31)
[09/30/2013 20:26:37 5b0] Calling m_Restore.ConnectServer(HWHOMEES)
[09/30/2013 20:26:37 5b0] m_Restore.ConnectServer OK
[09/30/2013 20:26:37 5b4] RestoreHelper::T_ConnectServer: Connected to server
[09/30/2013 20:26:39 5b4] PASS :ConnectionCompleteHandler::Completed succeeded (at func: Connection completed, backup\pc\client\homeservermanager\homeservermanager.cpp (22)
[09/30/2013 20:26:39 5b0] Calling m_Restore.Authenticate
[09/30/2013 20:26:39 5b0] m_Restore.Authenticate returned.
[09/30/2013 20:26:39 5b0] RequestPermissions returned 0, CanRestore=1
[09/30/2013 20:26:39 5b0] Calling m_Restore.RequestDatabaseState
[09/30/2013 20:26:39 5b0] Waiting for completion callback
[09/30/2013 20:26:39 5b4] T_RequestDatabaseState got database state 10
[09/30/2013 20:26:39 5b4] PASS :RequestCompleteHandler::Completed succeeded (at func: Request completed, backup\pc\client\homeservermanager\homeservermanager.cpp (31)
[09/30/2013 20:26:39 5b0] Calling m_Restore.RequestBackupMachines
[09/30/2013 20:26:39 5b0] Waiting for completion callback
[09/30/2013 20:26:39 5b4] PASS :RequestCompleteHandler::Completed succeeded (at func: Request completed, backup\pc\client\homeservermanager\homeservermanager.cpp (31)
[09/30/2013 20:26:39 5b0] Calling m_Restore.RetrieveBackupMachines
[09/30/2013 20:26:39 5b0] m_Restore.RetrieveBackupMachines returned 8 servers
[09/30/2013 20:26:39 5b0] Found backup machine <HWHOME34>
[09/30/2013 20:26:39 5b0] Found backup machine <HWHOME33>
[09/30/2013 20:26:39 5b0] Found backup machine <HWHOME41>
[09/30/2013 20:26:39 5b0] Found backup machine <HWHOME9>
[09/30/2013 20:26:39 5b0] Found backup machine <HWHOME10>
[09/30/2013 20:26:39 5b0] Found backup machine <HWHOME16>
[09/30/2013 20:26:39 5b0] Found backup machine <HWHOME3>
[09/30/2013 20:26:39 5b0] Found backup machine <HWHOME91>
[09/30/2013 20:26:44 5b0] Calling m_Restore.RequestBackupSets
[09/30/2013 20:26:44 5b4] PASS :RequestCompleteHandler::Completed succeeded (at func: Request completed, backup\pc\client\homeservermanager\homeservermanager.cpp (31)
[09/30/2013 20:26:44 5b4] Calling m_Restore.RetrieveBackupSets
[09/30/2013 20:26:44 5b4] m_Restore.RetrieveBackupSets returned 6 backups
[09/30/2013 20:26:44 5b0] PASS :GetStartDateTimeString succeeded (at func: GetDateTimeFormat, backup\pc\bmr\restorewizard\backupsetutils.h (45)
[09/30/2013 20:26:44 5b0] Adding backup set, status=Erfolgreich, time=28.03.2013 19:42:46, size=34,72 GB, description=2013-03-28 Manuelle Sicherung
[09/30/2013 20:26:44 5b0] PASS :GetStartDateTimeString succeeded (at func: GetDateTimeFormat, backup\pc\bmr\restorewizard\backupsetutils.h (45)
[09/30/2013 20:26:44 5b0] Adding backup set, status=Erfolgreich, time=12.07.2013 21:49:12, size=0,99 GB, description=2013-07-12 Manuelle Sicherung
[09/30/2013 20:26:44 5b0] PASS :GetStartDateTimeString succeeded (at func: GetDateTimeFormat, backup\pc\bmr\restorewizard\backupsetutils.h (45)
[09/30/2013 20:26:44 5b0] Adding backup set, status=Erfolgreich, time=26.07.2013 21:16:08, size=5,44 GB, description=2013-07-26 Manuelle Sicherung
[09/30/2013 20:26:44 5b0] PASS :GetStartDateTimeString succeeded (at func: GetDateTimeFormat, backup\pc\bmr\restorewizard\backupsetutils.h (45)
[09/30/2013 20:26:44 5b0] Adding backup set, status=Erfolgreich, time=21.08.2013 21:06:46, size=1,67 GB, description=Automatische Sicherung
[09/30/2013 20:26:44 5b0] PASS :GetStartDateTimeString succeeded (at func: GetDateTimeFormat, backup\pc\bmr\restorewizard\backupsetutils.h (45)
[09/30/2013 20:26:44 5b0] Adding backup set, status=Erfolgreich, time=20.09.2013 20:55:33, size=0,48 GB, description=Automatische Sicherung
[09/30/2013 20:26:44 5b0] PASS :GetStartDateTimeString succeeded (at func: GetDateTimeFormat, backup\pc\bmr\restorewizard\backupsetutils.h (45)
[09/30/2013 20:26:44 5b0] Adding backup set, status=Erfolgreich, time=22.09.2013 19:27:21, size=19,17 GB, description=2013-09-22 Manuelle Sicherung
[09/30/2013 20:26:46 5b0] Calling m_Restore.RequestVolumes
[09/30/2013 20:26:46 5b4] PASS :RequestCompleteHandler::Completed succeeded (at func: Request completed, backup\pc\client\homeservermanager\homeservermanager.cpp (31)
[09/30/2013 20:26:46 5b4] Calling m_Restore.RetrieveVolumes
[09/30/2013 20:26:46 5b4] m_Restore.RetrieveVolumes returned 3 volumes
[09/30/2013 20:26:56 5cc] Calling PhysicalVolumeInfo::GetAll
[09/30/2013 20:27:02 5cc] Unintialized disk(\\?\PhysicalDrive0), pDiskProp->status=1, pDiskProp->dwMediaType=12
ERROR: Could not get the unique id, 87 (ignoring the error)
[09/30/2013 20:27:02 5cc] PhysicalVolumeInfo::GetAll returned 0 volumes, filtered to 0 volumes
[09/30/2013 20:27:02 5b4] Unintialized disk(\\?\PhysicalDrive0), pDiskProp->status=1, pDiskProp->dwMediaType=12
ERROR: Could not get the unique id, 87 (ignoring the error)
[09/30/2013 20:27:02 5b4] Found 1 disk entries
[09/30/2013 20:27:02 5b4] Disk: \\?\PhysicalDrive0
[09/30/2013 20:27:02 5b0] RestoreHelper::CanDoAutoPartition started
[09/30/2013 20:27:02 5b0] Found disk: \\?\PhysicalDrive0
[09/30/2013 20:27:02 5b0] Size: 644396613632
[09/30/2013 20:27:02 5b0] mediaType: 0xc
[09/30/2013 20:27:02 5b0] No existing partition for volume (Offset=1048576, Size=104857600), must flatten disk
[09/30/2013 20:27:02 5b0] No existing partition for volume System (Offset=105906176, Size=107374182400), must flatten disk
[09/30/2013 20:27:02 5b0] No existing partition for volume Daten (Offset=107480088576, Size=391550861312), must flatten disk
[09/30/2013 20:27:02 5b0] Disk Size=644396613632, Total Source Volume Size=499029901312, CanReuse=0
[09/30/2013 20:27:02 5b0] Last Volume Size=391550861312, Last Volume Min Size=391550857728, LastVolumeOffset=107480088576
[09/30/2013 20:27:02 5b0] endOfLastVolume=499031998464, modifiedLastVolumeSize=536915476480
[09/30/2013 20:27:11 5b0] PASS :GetStartDateTimeString succeeded (at func: GetDateTimeFormat, backup\pc\bmr\restorewizard\backupsetutils.h (45)
[09/30/2013 20:27:12 5cc] Calling PhysicalVolumeInfo::GetAll
[09/30/2013 20:27:12 5cc] Unintialized disk(\\?\PhysicalDrive0), pDiskProp->status=1, pDiskProp->dwMediaType=12
ERROR: Could not get the unique id, 87 (ignoring the error)
[09/30/2013 20:27:12 5cc] PhysicalVolumeInfo::GetAll returned 0 volumes, filtered to 0 volumes
[09/30/2013 20:27:17 5b0] gpt warning = 0
[09/30/2013 20:27:17 5b0] PASS :GetStartDateTimeString succeeded (at func: GetDateTimeFormat, backup\pc\bmr\restorewizard\backupsetutils.h (45)
[09/30/2013 20:27:17 5cc] Calling PhysicalVolumeInfo::GetAll
[09/30/2013 20:27:17 5cc] Unintialized disk(\\?\PhysicalDrive0), pDiskProp->status=1, pDiskProp->dwMediaType=12
ERROR: Could not get the unique id, 87 (ignoring the error)
[09/30/2013 20:27:17 5cc] PhysicalVolumeInfo::GetAll returned 0 volumes, filtered to 0 volumes
[09/30/2013 20:27:17 5b0] Calling m_Restore.Restore
[09/30/2013 20:27:17 5b0] ReconnectableStream: Created ClientReconnectableStream for {8D9A5FFB-AE2E-4698-B375-2E16DF5FCD8A}, sizes 16384,10485760,10485760,16384
[09/30/2013 20:27:17 5b0] Restore - we are in reconnectable state
[09/30/2013 20:27:17 5b0] Restore started.
[09/30/2013 20:27:19 6b8] Searching for disk \\?\PhysicalDrive0
[09/30/2013 20:27:20 6b8] Cleaning disk
[09/30/2013 20:27:20 6b8] Creating volume:
[09/30/2013 20:27:20 6b8] Done creating volume
[09/30/2013 20:27:20 6b8] Enter FormatVolume
[09/30/2013 20:27:20 6b8] Formatting
[09/30/2013 20:27:21 6b8] Done formatting volume
[09/30/2013 20:27:21 6b8] Volume<GUID>: \\?\Volume{24c404be-2a06-11e3-af35-08002755fe08}\
[09/30/2013 20:27:21 6b8] Creating volume: System
[09/30/2013 20:27:21 6b8] Done creating volume
[09/30/2013 20:27:21 6b8] Enter FormatVolume
[09/30/2013 20:27:21 6b8] Formatting System
[09/30/2013 20:27:28 6b8] Done formatting volume
[09/30/2013 20:27:28 6b8] Volume<GUID>: \\?\Volume{24c404c5-2a06-11e3-af35-08002755fe08}\
[09/30/2013 20:27:28 6b8] Creating volume: Daten
[09/30/2013 20:27:28 6b8] Done creating volume
[09/30/2013 20:27:28 6b8] Enter FormatVolume
[09/30/2013 20:27:28 6b8] Formatting Daten
[09/30/2013 20:27:36 6b8] Done formatting volume
[09/30/2013 20:27:36 6b8] Volume<GUID>: \\?\Volume{24c404cc-2a06-11e3-af35-08002755fe08}\
[09/30/2013 20:27:36 6b8] CreateBackupVolumes returned 0x00000000, with 3 volume names.
[09/30/2013 20:27:36 6b8] T_Restore staring the restore of 3 volumes
[09/30/2013 20:27:36 6b8] RestoreHelper::T_Restore: restoring source volume:
[09/30/2013 20:27:36 6b8] RestoreHelper::T_Restore: sending SendBeginRestoreReq
[09/30/2013 20:27:36 6b8] RestoreHelper::T_Restore: entering the server queue
[09/30/2013 20:27:36 6b8] RestoreHelper::T_Restore: we're out of the server queue
[09/30/2013 20:27:36 6b8] RestoreHelper::T_Restore: sending RecvBeginRestoreResp
[09/30/2013 20:27:37 6b8] RestoreHelper::GetUsedSpaceBitmap: getting used space bitmap
[09/30/2013 20:27:38 6b8] T_Restore entering restore loop (downloading data). Start=0, Count=25056l
[09/30/2013 20:27:39 6b8] RestoreHelper::FixBootBlock: fixing boot block
[09/30/2013 20:27:39 6b8] RestoreHelper::ExtendVolume: extending the volume
[09/30/2013 20:27:40 6b8] RestoreHelper::SetVolumeActive: setting volume active
[09/30/2013 20:27:40 6b8] RestoreHelper::T_Restore: restoring source volume: C:\
[09/30/2013 20:27:40 6b8] RestoreHelper::T_Restore: sending SendBeginRestoreReq
[09/30/2013 20:27:40 6b8] RestoreHelper::T_Restore: entering the server queue
[09/30/2013 20:27:40 6b8] RestoreHelper::T_Restore: we're out of the server queue
[09/30/2013 20:27:46 6b8] RestoreHelper::T_Restore: sending RecvBeginRestoreResp
[09/30/2013 20:27:46 6b8] IoCtl::LockVolume GetOverlappedResult failed with 5
[09/30/2013 20:27:46 6b8]
FSCTL_LOCK_VOLUME failed with 5, retrying in 1 second
[09/30/2013 20:27:47 6b8] IoCtl::LockVolume GetOverlappedResult failed with 5
[09/30/2013 20:27:47 6b8]
FSCTL_LOCK_VOLUME failed with 5, retrying in 1 second
[09/30/2013 20:27:48 6b8] IoCtl::LockVolume GetOverlappedResult failed with 5
[09/30/2013 20:27:48 6b8]
FSCTL_LOCK_VOLUME failed with 5, retrying in 1 second
[09/30/2013 20:27:49 6b8] Volume::Initialize: IoCtl::LockVolume failed with 5
[09/30/2013 20:27:49 6b8] RestoreHelper::T_Restore: restore complete with return value 31
[09/30/2013 20:27:49 6b8] ERROR: CDialog_Restore::Completed failed, HR=0x8007001F (at func: CDialog_Restore::Completed, backup\pc\bmr\restorewizard\dialog_restore.cpp (93)
[09/30/2013 20:29:32 5b0] Running cmd.exe.