locked
nightly WHS backup service thinks it is finished after client wakes up (i.e., doesn't run) RRS feed

  • Question

  • Hi, I have an HP MediaSmart EX475 running WHS.  Nightly backups have been working great for almost a year now, but recently they stopped working.  I've been trying to resolve this issue for a week, and after untold amounts of research, I'm not having any luck.  I'm desperately hoping someone here could help...

    Here are the details about the configuration:

    Nightly backups are set to run at 3:00AM.  The client machine is plugged in to the wall and not on a UPS.  It is put into sleep mode nightly several hours prior to the 3:00AM backup time.  I've reinstalled the connector client on the machine.  I've reconfigured backups from scratch.  Manual backups work just fine.  The client hard drive passes "chkdsk" fine.  The client is an XP machine.

    The situation is this:  The client wakes at 3:00AM, connects to the WHS server, does a few things, and then thinks the back up is "done", and finishes.  I.e., the backup process itself doesn't run anymore (!).

    Here are the client and server logs for an example "failure", from this morning --

    client log (WHSTrayApp.100509_2396.log)
    ---------------------------------------

    The client machine wakes at 3:00AM, then takes a while to connect to the server transport.  It finally connects, then does the normal "removing health issue" process, then decides that the "Backup is done" with a zero failure reason, and that is it (??!).  It never kicks off the backup process with the server.

    [10/5/2009 3:02:03 AM  a9c] ERROR: m_transportService->GetTransportStatus returns connected=0.
    [10/5/2009 3:02:08 AM  a9c] ERROR: m_transportService->GetTransportStatus returns connected=0.
    [10/5/2009 3:12:29 AM  a9c] ERROR: m_transportService->GetTransportStatus returns connected=0.
    [10/5/2009 3:12:37 AM  a9c] ERROR: m_transportService->GetTransportStatus returns connected=0.
    [10/5/2009 3:12:38 AM  e64] WARN : HealthTrayOperation::OnNotificationArrived: Notification sink connected!
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<WHS.Backup.CurrentOperation>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<WHS.Backup.Machine.{78A3357B-6829-4F9F-83C2-BD79D74D8399}>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<WHS.Backup.Machine.{9C95C1FE-3BEB-4F41-A0CA-B338BE83C8B1}>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<WHS.Backup.Machine.{B07523B9-F319-4B21-B9F9-DA4949424ADF}>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<WHS.Backup.Startup>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<HPAddInMonitor-cfcd4af6-203d-4213-bab4-3c140954287b>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<HPMediaSmart-CPU-Temperature>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<HPMediaSmart-Fan-Speeds>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<HPMediaSmart-Software-Updates>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<HPMediaSmart-Voltages>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<TZO-DDNS-Service-Notice>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<qsm.00008186-058d-4c89-ab57-a7f909a47ab5.Object>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<qsm.0fb0c498-d4cb-4e02-8f8a-770c6ee06fe9.Object>
                                                   ...
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<qsm.bf012b42-31f7-4f00-8d1a-190c9191f0c1.Object>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<qsm.e0d7e1c9-83c1-4134-bf8d-34de1400fe02.Object>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<WHS.Backup.Machine.{B07523B9-F319-4B21-B9F9-DA4949424ADF}>
    [10/5/2009 3:12:38 AM  e64] WARN : Removing health issue: id=<WHS.Backup.Machine.{B07523B9-F319-4B21-B9F9-DA4949424ADF}>
    [10/5/2009 3:12:39 AM  c4c] WARN : Backup is done, failureReason=0.
    [10/5/2009 3:12:42 AM  a9c] WARN : Transport state changed, new state=0
    [10/5/2009 3:12:42 AM  a9c] SingleIconTrayApplication::ChangeActiveOperationIfNeeded: active operation  TransportStatusTrayOperation (0x6FB74) stopped, draining notifications.
    [10/5/2009 3:12:42 AM  a9c] WARN : SingleIconTrayApplication::UpdateTrayData active operation=HealthTrayOperation(0x6F434), activeOperationChanged=1
    [10/5/2009 3:12:42 AM  a9c] WARN : SingleIconTrayApplication::UpdateTrayData changing icon from (0x30187) to (0x30157)
    [10/5/2009 3:12:42 AM  a9c] Icon for app 0x6F608 is now 0x30157
    [10/5/2009 3:12:59 AM  15c] ERROR: hr=0x80070102 (at func: PasswordSyncTrayOperation::CheckIfUserExistsOnServer, d:\wssg_src\whs_pp2\qhs\src\client\trayapp\passwordsynctrayoperation.cpp (217)) hr 14007
    [10/5/2009 3:12:59 AM  15c] ERROR: hr=0x80070102 (at func: PasswordSyncTrayOperation::UpdateStatus, d:\wssg_src\whs_pp2\qhs\src\client\trayapp\passwordsynctrayoperation.cpp (283)) hr 14007
    [10/5/2009 3:14:44 AM  e64] SingleIconTrayApplication::ChangeActiveOperationIfNeeded: active operation  HealthTrayOperation (0x6F434) updated, severity might have changed. Refreshing active.
    [10/5/2009 3:14:44 AM  e64] WARN : HealthTrayOperation::OnNotificationArrived: Notification sink disconnected!


    Server transport log (Transport.100509.log)
    -------------------------------------------

    The server transport receives the client connection, then doesn't do much.

    [2009/10/05 03:12:06  acc]   CTransportPipe::Open Pipe 8 to {B07423C9-F319-4B21-...} is opened, hr=00000000
    [10/5/2009 3:14:13 AM 1708] Partner shut down the connection
    [10/5/2009 3:14:13 AM 1708] Read 0 bytes, hr=80004004


    There is no server backup process log from this morning (e.g., BackupEngine...log) as the system never started the actual backup.


    Working backup client log from last week (WHSTrayApp.092709_2212.log)
    ---------------------------------------------------------------------

    Looking at a log from last week, the client connected more quickly to the server, and the backup got started just fine.  Here is an excerpt:

    [9/27/2009 3:00:13 AM]
    [9/27/2009 3:00:13 AM  8e8] WARN : Transport state changed, new state=1
    [9/27/2009 3:00:13 AM  8e8] SingleIconTrayApplication::ChangeActiveOperationIfNeeded: Temporary operation TransportStatusTrayOperation (0x6FB74) started
    [9/27/2009 3:00:16 AM  8e8] WARN : SingleIconTrayApplication::UpdateTrayData active operation=TransportStatusTrayOperation(0x6FB74), activeOperationChanged=1
    [9/27/2009 3:00:16 AM  8e8] WARN : SingleIconTrayApplication::UpdateTrayData changing icon from (0x101FB) to (0x10205)
    [9/27/2009 3:00:16 AM  8e8] Icon for app 0x6F608 is now 0x10205
    [9/27/2009 3:00:22 AM  8e8] WARN : Transport state changed, new state=0
    [9/27/2009 3:00:22 AM  8e8] SingleIconTrayApplication::ChangeActiveOperationIfNeeded: active operation  TransportStatusTrayOperation (0x6FB74) stopped, draining notifications.
    [9/27/2009 3:00:22 AM  8e8] WARN : SingleIconTrayApplication::UpdateTrayData active operation=HealthTrayOperation(0x6F434), activeOperationChanged=1
    [9/27/2009 3:00:22 AM  8e8] WARN : SingleIconTrayApplication::UpdateTrayData changing icon from (0x10205) to (0x101FB)
    [9/27/2009 3:00:22 AM  8e8] Icon for app 0x6F608 is now 0x101FB
    [9/27/2009 3:00:22 AM  8ac] WARN : HealthTrayOperation::OnNotificationArrived: Notification sink connected!
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.CurrentOperation>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.Machine.{78A3357B-6829-4F9F-83C2-BD79D74D8399}>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.Machine.{9C95C1FE-3BEB-4F41-A0CA-B338BE83C8B1}>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.Machine.{B07523B9-F319-4B21-B9F9-DA4949424ADF}>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.Startup>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<HPAddInMonitor-cfcd4bf6-203d-4213-bab4-3c140954287b>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<HPMediaSmart-CPU-Temperature>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<HPMediaSmart-Fan-Speeds>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<HPMediaSmart-Software-Updates>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<HPMediaSmart-Voltages>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<TZO-DDNS-Service-Notice>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<qsm.00008186-058d-4c89-ab57-a7f909a47ab5.Object>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<qsm.0fb0c498-d4cb-4e02-8f8a-770c6ee06fe9.Object>
                                                   ...
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<qsm.cee30517-4ab9-480c-b786-5a1a00632aff.Object>
    [9/27/2009 3:00:23 AM  8ac] WARN : Removing health issue: id=<qsm.e0d7e1c9-83c1-4134-bf8d-34de1400fe02.Object>
    [9/27/2009 3:00:24 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.Machine.{B07523B9-F319-4B21-B9F9-DA4949424ADF}>
    [9/27/2009 3:00:24 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.Machine.{B07523B9-F319-4B21-B9F9-DA4949424ADF}>
    [9/27/2009 3:00:29 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.CurrentOperation>
    [9/27/2009 3:00:32 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.CurrentOperation>
    [9/27/2009 3:00:36 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.CurrentOperation>
    [9/27/2009 3:00:38 AM  8ec] WARN : Backup is starting.
    [9/27/2009 3:00:38 AM  8ec] SingleIconTrayApplication::ChangeActiveOperationIfNeeded: Temporary operation BackupTrayOperation (0x6F234) started
    [9/27/2009 3:00:38 AM  8ec] WARN : SingleIconTrayApplication::UpdateTrayData active operation=BackupTrayOperation(0x6F234), activeOperationChanged=1
    [9/27/2009 3:00:38 AM  8ec] WARN : SingleIconTrayApplication::UpdateTrayData changing icon from (0x101FB) to (0x10201)
    [9/27/2009 3:00:38 AM  8ec] Icon for app 0x6F608 is now 0x10201
    [9/27/2009 3:00:40 AM  8ac] WARN : Removing health issue: id=<WHS.Backup.CurrentOperation>


    Any help would be really, really, really, really appreciated...  :-)

    Thanks!


    Monday, October 5, 2009 4:39 PM

All replies

  • Have you tried rebooting the server? That would be the first thing I'd do.............I'd ponder what to do next............

    Cruise
    Monday, October 5, 2009 11:15 PM
  • If a reboot does not fix it, a "chkdsk /f /r" on the client and/or server would be the next step
    Monday, October 5, 2009 11:18 PM
  • Yes, I've rebooted it (and the client) many times...
    Monday, October 5, 2009 11:40 PM
  • If a reboot does not fix it, a "chkdsk /f /r" on the client and/or server would be the next step

    Yes, I've done that as well on both the client and the server...
    Monday, October 5, 2009 11:41 PM
  • I'd probably think about a server reinstall. Looks like there are a lot of HP MediaSmart health warnings showing up. I'd guess it's still server related. Does it backup anything (on any PC attached)? If not, it almost has to be server related. It was working and does not now, server............

    Cruise
    Tuesday, October 6, 2009 12:28 AM
  • I'd probably think about a server reinstall. Looks like there are a lot of HP MediaSmart health warnings showing up. I'd guess it's still server related. Does it backup anything (on any PC attached)? If not, it almost has to be server related. It was working and does not now, server............

    Cruise
    Yes, manual backups initiated from either the client or the server work fine.

    I may just have to try a server reinstall....sigh...
    Tuesday, October 6, 2009 1:44 AM